Here's the report from Radek.
I’m using devstack with congress with merged your commit 59f95702949108df9553cacc2403a90be1490942 of https://review.openstack.org/#/c/167824/1
. The last commit (of my devstack’s congress) is a1b3ab9bc7849767ddd21a9b5551440663e18ea1 .
The defect is HTTP 500 and 409, when I’m trying to add rule.
What I did:
· Created policy and rules as described in https://wiki.openstack.org/wiki/PolicyGuidedFulfillmentDemo#Policy_Rules
· After some time (approx hour) I decided to add another rule
devstack@mydpha061:~/devstack$ openstack congress policy rule create murano_system 'allowedApp("io.murano.apps.java.HelloWorld")'
/usr/local/lib/python2.7/dist-packages/novaclient/v1_1/__init__.py:30: UserWarning: Module novaclient.v1_1 is deprecated (taken as a basis for novaclient.v2). The preferable way to get client class or object you can find in novaclient.client module.
warnings.warn("Module novaclient.v1_1 is deprecated (taken as a basis for "
ERROR: openstack Internal server error (HTTP 500) (Request-ID: req-9e416fed-e3a4-444d-a671-1fd77bd41288)
devstack@mydpha061:~/devstack$ openstack congress policy rule list murano_system
/usr/local/lib/python2.7/dist-packages/novaclient/v1_1/__init__.py:30: UserWarning: Module novaclient.v1_1 is deprecated (taken as a basis for novaclient.v2). The preferable way to get client class or object you can find in novaclient.client module.
warnings.warn("Module novaclient.v1_1 is deprecated (taken as a basis for "
// ID: 3d2a26ff-b4af-4b56-ba0f-b05845e86189
// Name: None
allowedApp("io.murano.apps.java.PetClinic", "demo")
// ID: 4250588e-7a60-4d01-ac57-a21f768bd445
// Name: None
allowedApp("io.murano.databases.MySql", "demo")
// ID: 46c2bcc4-bc9b-4ca5-a403-4156785193be
// Name: None
allowedApp("io.murano.apps.apache.Tomcat", "demo")
// ID: 5caffb52-a9ff-4cf8-a944-d8ecf5b1022c
// Name: None
tenantName(tid, tname) :- keystone:tenants(en,desc,tname,tid)
// ID: 97fa7322-6669-445b-890f-75984ecf87f3
// Name: None
allowedApp("io.murano.apps.java.PetClinic", "qa")
// ID: 9ca32885-0659-48b4-ba3f-a64c98bc2090
// Name: None
objName(oid,oname) :- murano:properties(oid, "name", oname)
// ID: ab568016-7218-4a41-a586-d217266f0da6
// Name: None
allowedApp("io.murano.apps.apache.Tomcat", "qa")
// ID: c6d961bb-e848-49de-9f5c-01a6e8a8cf1c
// Name: None
predeploy_errors(eid,oid,msg) :- murano:objects(oid,eid,type), murano:properties(eid,"tenant_id",tid), murano:parent_types(oid,"io.murano.Application"), tenantName(tid,tname), not allowedApp(type, tname),concat("Unsupported application detected: ", type, tmsg1),concat(tmsg1, ", ", tmsg2),objName(oid, oname), concat(tmsg2, oname, msg)
// ID: f54f2b65-4615-40d7-9a43-8ce4fd346d51
// Name: None
allowedApp("io.murano.databases.PostgreSql", "qa")
devstack@mydpha061:~/devstack$ openstack congress policy rule create murano_system 'allowedApp("io.murano.apps.java.HelloWorld")'
/usr/local/lib/python2.7/dist-packages/novaclient/v1_1/__init__.py:30: UserWarning: Module novaclient.v1_1 is deprecated (taken as a basis for novaclient.v2). The preferable way to get client class or object you can find in novaclient.client module.
warnings.warn("Module novaclient.v1_1 is deprecated (taken as a basis for "
ERROR: openstack Rule already exists (HTTP 409) (Request-ID: req-0f0f9281-0128-4acc-be88-f93344621884) Here I’ve received 409 not 500 as in previous case
devstack@mydpha061:~/devstack$ screen -r stack
I stopped congress server in the screen
[1]+ Stopped screen -r stack
devstack@mydpha061:~/devstack$ openstack congress policy rule create murano_system 'allowedApp("io.murano.apps.java.HelloWorld")'
/usr/local/lib/python2.7/dist-packages/novaclient/v1_1/__init__.py:30: UserWarning: Module novaclient.v1_1 is deprecated (taken as a basis for novaclient.v2). The preferable way to get client class or object you can find in novaclient.client module.
warnings.warn("Module novaclient.v1_1 is deprecated (taken as a basis for "
ERROR: openstack Unable to establish connection to http://16.60.142.48:1789/v1/policies/murano_system/rules server was stopped, so response is correct
devstack@mydpha061:~/devstack$ screen -r stack
I started congress server in the screen
[2]+ Stopped screen -r stack
devstack@mydpha061:~/devstack$ openstack congress policy rule create murano_system 'allowedApp("io.murano.apps.java.HelloWorld")'
/usr/local/lib/python2.7/dist-packages/novaclient/v1_1/__init__.py:30: UserWarning: Module novaclient.v1_1 is deprecated (taken as a basis for novaclient.v2). The preferable way to get client class or object you can find in novaclient.client module.
warnings.warn("Module novaclient.v1_1 is deprecated (taken as a basis for "
+---------+----------------------------------------------+
| Field | Value |
+---------+----------------------------------------------+
| comment | None |
| id | 9ba7b181-b6a2-4bc2-b61a-bc2ece20075d |
| name | None |
| rule | allowedApp("io.murano.apps.java.HelloWorld") |
+---------+----------------------------------------------+
devstack@mydpha061:~/devstack$ date
Fri Mar 27 15:40:35 CET 2015
Here are logs:
2015-03-27 15:39:15.486 12150 DEBUG congress.datasources.ceilometer_driver [-] Getting all Resource ID for meter: memory update_from_datasource /opt/stack/congress/congress/datasources/ceilometer_driver.py:197
2015-03-27 15:39:15.502 12150 DEBUG congress.datasources.ceilometer_driver [-] Statistics List: [<Statistics {u'count': 11, u'duration_start': u'2015-03-27T13:54:09.194362', u'min': 4096.0, u'max': 4096.0, u'duration_end': u'2015-03-27T14:00:56.426446', u'period': 0, u'groupby': {u'resource_id': u'c9eb39d0-b054-4b81-8096-77a1907b4bcc'}, u'period_end': u'2015-03-27T14:00:56.426446', u'duration': 407.232084, u'period_start': u'2015-03-27T13:54:09.194362', u'avg': 4096.0, u'sum': 45056.0, u'unit': u'MB'}>, <Statistics {u'count': 18, u'duration_start': u'2015-03-27T13:42:09.493685', u'min': 4096.0, u'max': 4096.0, u'duration_end': u'2015-03-27T14:00:56.443346', u'period': 0, u'groupby': {u'resource_id': u'ce293f6d-1eef-43d7-882a-1eb6bd428a79'}, u'period_end': u'2015-03-27T14:00:56.443346', u'duration': 1126.949661, u'period_start': u'2015-03-27T13:42:09.493685', u'avg': 4096.0, u'sum': 73728.0, u'unit': u'MB'}>] update_from_datasource /opt/stack/congress/congress/datasources/ceilometer_driver.py:200
2015-03-27 15:39:15.502 12150 DEBUG congress.datasources.ceilometer_driver [-] Getting all Resource ID for meter: disk.write.bytes.rate update_from_datasource /opt/stack/congress/congress/datasources/ceilometer_driver.py:197
2015-03-27 15:39:15.518 12150 DEBUG congress.datasources.ceilometer_driver [-] Statistics List: [<Statistics {u'count': 4, u'duration_start': u'2015-03-27T14:05:06', u'min': 0.0, u'max': 823029.76, u'duration_end': u'2015-03-27T14:35:06', u'period': 0, u'groupby': {u'resource_id': u'c9eb39d0-b054-4b81-8096-77a1907b4bcc'}, u'period_end': u'2015-03-27T14:35:06', u'duration': 1800.0, u'period_start': u'2015-03-27T14:05:06', u'avg': 205810.34666666668, u'sum': 823241.3866666667, u'unit': u'B/s'}>] update_from_datasource /opt/stack/congress/congress/datasources/ceilometer_driver.py:200
2015-03-27 15:39:15.519 12150 DEBUG congress.datasources.ceilometer_driver [-] Getting all Resource ID for meter: network.outgoing.bytes.rate update_from_datasource /opt/stack/congress/congress/datasources/ceilometer_driver.py:197
2015-03-27 15:39:15.533 12150 DEBUG congress.datasources.ceilometer_driver [-] Statistics List: [<Statistics {u'count': 4, u'duration_start': u'2015-03-27T14:05:06', u'min': 0.0, u'max': 644.393333333333, u'duration_end': u'2015-03-27T14:35:06', u'period': 0, u'groupby': {u'resource_id': u'instance-00000002-c9eb39d0-b054-4b81-8096-77a1907b4bcc-tap114616dd-35'}, u'period_end': u'2015-03-27T14:35:06', u'duration': 1800.0, u'period_start': u'2015-03-27T14:05:06', u'avg': 161.09833333333324, u'sum': 644.393333333333, u'unit': u'B/s'}>] update_from_datasource /opt/stack/congress/congress/datasources/ceilometer_driver.py:200
2015-03-27 15:39:15.534 12150 DEBUG congress.datasources.ceilometer_driver [-] Getting all Resource ID for meter: disk.device.allocation update_from_datasource /opt/stack/congress/congress/datasources/ceilometer_driver.py:197
2015-03-27 15:39:15.537 12150 DEBUG keystoneclient.session [-] RESP: [200] content-length: 9938 x-subject-token: {SHA1}faa8766abec3052f888623608a9d8dfb64246747 vary: X-Auth-Token keep-alive: timeout=5, max=100 server: Apache/2.4.7 (Ubuntu) connection: Keep-Alive date: Fri, 27 Mar 2015 14:39:15 GMT content-type: application/json x-openstack-request-id: req-2ee4176d-f307-4495-8fc1-292a43179345
RESP BODY: {"token": {"methods": ["password", "token"], "roles": [{"id": "91c94f8d6693417f9840541e7ebd1333", "name": "admin"}], "expires_at": "2015-03-27T15:39:15.000000Z", "project": {"domain": {"id": "default", "name": "Default"}, "id": "060f46bc030c411481935e5cfb2c5c70", "name": "admin"}, "catalog": "<removed>", "extras": {}, "user": {"domain": {"id": "default", "name": "Default"}, "id": "81db037a8aa247aaacf27098ff5e4005", "name": "admin"}, "audit_ids": ["twACY9PkRZeky0TlFitgSg"], "issued_at": "2015-03-27T14:39:15.432473"}}
_http_log_response /usr/local/lib/python2.7/dist-packages/keystoneclient/session.py:224
2015-03-27 15:39:15.539 12150 DEBUG congress.api.application [req-9e416fed-e3a4-444d-a671-1fd77bd41288 None] Handling request 'POST /v1/policies/murano_system/rules' with CollectionHandler(/v1/policies/(?P<policy_id>[^/]+)/rules$) __call__ /opt/stack/congress/congress/api/application.py:45
2015-03-27 15:39:15.541 12150 DEBUG congress.dse.deepsix [req-9e416fed-e3a4-444d-a671-1fd77bd41288 None] engine:: process_policy_update [<congress.datalog.compile.Event object at 0x7ff1b134f8c0>] log_debug /opt/stack/congress/congress/dse/deepsix.py:565
2015-03-27 15:39:15.544 12150 DEBUG congress.datalog.base [req-9e416fed-e3a4-444d-a671-1fd77bd41288 None] RT : Updating with <congress.datalog.utility.iterstr object at 0x7ff1b07cb1d0> log /opt/stack/congress/congress/datalog/base.py:46
2015-03-27 15:39:15.545 12150 DEBUG congress.datalog.base [req-9e416fed-e3a4-444d-a671-1fd77bd41288 None] muran : update_would_cause_errors <congress.datalog.utility.iterstr object at 0x7ff1b07cb1d0> log /opt/stack/congress/congress/datalog/base.py:46
2015-03-27 15:39:15.545 12150 DEBUG congress.datalog.base [req-9e416fed-e3a4-444d-a671-1fd77bd41288 None] muran : Update <congress.datalog.utility.iterstr object at 0x7ff1b07cb1d0> log /opt/stack/congress/congress/datalog/base.py:46
2015-03-27 15:39:15.546 12150 DEBUG congress.datalog.base [req-9e416fed-e3a4-444d-a671-1fd77bd41288 None] muran : Insert: allowedApp("io.murano.apps.java.HelloWorld") log /opt/stack/congress/congress/datalog/base.py:46
2015-03-27 15:39:15.546 12150 ERROR congress.datalog.nonrecursive [req-9e416fed-e3a4-444d-a671-1fd77bd41288 None] runtime caught an exception
2015-03-27 15:39:15.546 12150 TRACE congress.datalog.nonrecursive Traceback (most recent call last):
2015-03-27 15:39:15.546 12150 TRACE congress.datalog.nonrecursive File "/opt/stack/congress/congress/datalog/nonrecursive.py", line 85, in update
2015-03-27 15:39:15.546 12150 TRACE congress.datalog.nonrecursive if self._insert_actual(formula):
2015-03-27 15:39:15.546 12150 TRACE congress.datalog.nonrecursive File "/opt/stack/congress/congress/datalog/nonrecursive.py", line 161, in _insert_actual
2015-03-27 15:39:15.546 12150 TRACE congress.datalog.nonrecursive return self.rules.add_rule(rule.head.table, rule)
2015-03-27 15:39:15.546 12150 TRACE congress.datalog.nonrecursive File "/opt/stack/congress/congress/datalog/ruleset.py", line 63, in add_rule
2015-03-27 15:39:15.546 12150 TRACE congress.datalog.nonrecursive return self.facts[key].add(f)
2015-03-27 15:39:15.546 12150 TRACE congress.datalog.nonrecursive File "/opt/stack/congress/congress/datalog/factset.py", line 56, in add
2015-03-27 15:39:15.546 12150 TRACE congress.datalog.nonrecursive self._add_fact_to_index(fact, index)
2015-03-27 15:39:15.546 12150 TRACE congress.datalog.nonrecursive File "/opt/stack/congress/congress/datalog/factset.py", line 152, in _add_fact_to_index
2015-03-27 15:39:15.546 12150 TRACE congress.datalog.nonrecursive k = self._compute_key(index, fact)
2015-03-27 15:39:15.546 12150 TRACE congress.datalog.nonrecursive File "/opt/stack/congress/congress/datalog/factset.py", line 146, in _compute_key
2015-03-27 15:39:15.546 12150 TRACE congress.datalog.nonrecursive return tuple([fact[i] for i in columns])
2015-03-27 15:39:15.546 12150 TRACE congress.datalog.nonrecursive IndexError: tuple index out of range
2015-03-27 15:39:15.546 12150 TRACE congress.datalog.nonrecursive
2015-03-27 15:39:15.547 12150 ERROR congress.api.application [req-9e416fed-e3a4-444d-a671-1fd77bd41288 None] Exception caught for request: POST /v1/policies/murano_system/rules HTTP/1.0 Accept: application/json Accept-Encoding: gzip, deflate Connection: keep-alive Content-Length: 58 Content-Type: application/json Host: 16.60.142.48:1789 User-Agent: python-congressclient X-Auth-Token: ac1573587d2b43e29cc595e29a98937c X-Domain-Id: None X-Domain-Name: None X-Identity-Status: Confirmed X-Project-Domain-Id: default X-Project-Domain-Name: Default X-Project-Id: 060f46bc030c411481935e5cfb2c5c70 X-Project-Name: admin X-Role: admin X-Roles: admin X-Service-Catalog: [{"endpoints": [{"adminURL": "http://16.60.142.48:9292", "region": "RegionOne", "internalURL": "http://16.60.142.48:9292", "publicURL": "http://16.60.142.48:9292"}], "type": "image", "name": "glance"}, {"endpoints": [{"adminURL": "http://16.60.142.48:8989/v2", "region": "RegionOne", "internalURL": "http://16.60.142.48:8989/v2", "publicURL": "http://16.60.142.48:8989/v2"}], "type": "workflowv2", "name": "mistral"}, {"endpoints": [{"adminURL": "http://16.60.142.48:8774/v2.1/060f46bc030c411481935e5cfb2c5c70", "region": "RegionOne", "internalURL": "http://16.60.142.48:8774/v2.1/060f46bc030c411481935e5cfb2c5c70", "publicURL": "http://16.60.142.48:8774/v2.1/060f46bc030c411481935e5cfb2c5c70"}], "type": "computev21", "name": "novav21"}, {"endpoints": [{"adminURL": "http://16.60.142.48:8989/v1", "region": "RegionOne", "internalURL": "http://16.60.142.48:8989/v1", "publicURL": "http://16.60.142.48:8989/v1"}], "type": "workflow", "name": "mistral"}, {"endpoints": [{"adminURL": "http://16.60.142.48:8777/", "region": "RegionOne", "internalURL": "http://16.60.142.48:8777/", "publicURL": "http://16.60.142.48:8777/"}], "type": "metering", "name": "ceilometer"}, {"endpoints": [{"adminURL": "http://16.60.142.48:8774/v2/060f46bc030c411481935e5cfb2c5c70", "region": "RegionOne", "internalURL": "http://16.60.142.48:8774/v2/060f46bc030c411481935e5cfb2c5c70", "publicURL": "http://16.60.142.48:8774/v2/060f46bc030c411481935e5cfb2c5c70"}], "type": "compute", "name": "nova"}, {"endpoints": [{"adminURL": "http://16.60.142.48:8004/v1/060f46bc030c411481935e5cfb2c5c70", "region": "RegionOne", "internalURL": "http://16.60.142.48:8004/v1/060f46bc030c411481935e5cfb2c5c70", "publicURL": "http://16.60.142.48:8004/v1/060f46bc030c411481935e5cfb2c5c70"}], "type": "orchestration", "name": "heat"}, {"endpoints": [{"adminURL": "http://16.60.142.48:8776/v2/060f46bc030c411481935e5cfb2c5c70", "region": "RegionOne", "internalURL": "http://16.60.142.48:8776/v2/060f46bc030c411481935e5cfb2c5c70", "publicURL": "http://16.60.142.48:8776/v2/060f46bc030c411481935e5cfb2c5c70"}], "type": "volumev2", "name": "cinderv2"}, {"endpoints": [{"adminURL": "http://16.60.142.48:8773/", "region": "RegionOne", "internalURL": "http://16.60.142.48:8773/", "publicURL": "http://16.60.142.48:8773/"}], "type": "ec2", "name": "ec2"}, {"endpoints": [{"adminURL": "http://16.60.142.48:35357/v2.0", "region": "RegionOne", "internalURL": "http://16.60.142.48:5000/v2.0", "publicURL": "http://16.60.142.48:5000/v2.0"}], "type": "identity", "name": "keystone"}, {"endpoints": [{"adminURL": "http://16.60.142.48:8000/v1", "region": "RegionOne", "internalURL": "http://16.60.142.48:8000/v1", "publicURL": "http://16.60.142.48:8000/v1"}], "type": "cloudformation", "name": "heat-cfn"}, {"endpoints": [{"adminURL": "http://16.60.142.48:8082", "region": "RegionOne", "internalURL": "http://16.60.142.48:8082", "publicURL": "http://16.60.142.48:8082"}], "type": "application_catalog", "name": "murano"}, {"endpoints": [{"adminURL": "http://16.60.142.48:3333", "region": "RegionOne", "internalURL": "http://16.60.142.48:3333", "publicURL": "http://16.60.142.48:3333"}], "type": "s3", "name": "s3"}, {"endpoints": [{"adminURL": "http://16.60.142.48:1789/", "region": "RegionOne", "internalURL": "http://16.60.142.48:1789/", "publicURL": "http://16.60.142.48:1789/"}], "type": "policy", "name": "congress"}, {"endpoints": [{"adminURL": "http://16.60.142.48:9696/", "region": "RegionOne", "internalURL": "http://16.60.142.48:9696/", "publicURL": "http://16.60.142.48:9696/"}], "type": "network", "name": "neutron"}, {"endpoints": [{"adminURL": "http://16.60.142.48:8776/v1/060f46bc030c411481935e5cfb2c5c70", "region": "RegionOne", "internalURL": "http://16.60.142.48:8776/v1/060f46bc030c411481935e5cfb2c5c70", "publicURL": "http://16.60.142.48:8776/v1/060f46bc030c411481935e5cfb2c5c70"}], "type": "volume", "name": "cinder"}] X-Tenant: admin X-Tenant-Id: 060f46bc030c411481935e5cfb2c5c70 X-Tenant-Name: admin X-User: admin X-User-Domain-Id: default X-User-Domain-Name: Default X-User-Id: 81db037a8aa247aaacf27098ff5e4005 X-User-Name: admin {"rule": "allowedApp(\"io.murano.apps.java.HelloWorld\")"}
2015-03-27 15:39:15.549 12150 ERROR congress.api.application [req-9e416fed-e3a4-444d-a671-1fd77bd41288 None] Traceback (most recent call last):
File "/opt/stack/congress/congress/api/application.py", line 47, in __call__
response = handler.handle_request(request)
File "/opt/stack/congress/congress/api/webservice.py", line 353, in handle_request
return self.create_member(request)
File "/opt/stack/congress/congress/api/webservice.py", line 392, in create_member
item, request.params, id_, context=context)
File "/opt/stack/congress/congress/api/rule_model.py", line 128, in add_item
changes = self.change_rule(rule, context)
File "/opt/stack/congress/congress/api/rule_model.py", line 180, in change_rule
(permitted, changes) = self.engine.process_policy_update([event])
File "/opt/stack/congress/congress/policy_engines/agnostic.py", line 1247, in process_policy_update
result = self.update(events)
File "/opt/stack/congress/congress/policy_engines/agnostic.py", line 460, in update
return self._update_obj(sequence, target)
File "/opt/stack/congress/congress/policy_engines/agnostic.py", line 637, in _update_obj
changes.extend(self.get_target(th).update(events))
File "/opt/stack/congress/congress/datalog/nonrecursive.py", line 92, in update
raise e
IndexError: tuple index out of range
....
2015-03-27 15:40:03.554 12150 DEBUG keystoneclient.session [-] REQ: curl -g -i --cacert "/opt/stack/data/ca-bundle.pem" -X GET http://16.60.142.48:35357/v3/auth/tokens -H "X-Subject-Token: {SHA1}a908e3dd85fe63f2e614d9dae2f5222c045508a4" -H "User-Agent: python-keystoneclient" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}3949e323401449c8816b673dbe6b21871422dcd8" _http_log_request /usr/local/lib/python2.7/dist-packages/keystoneclient/session.py:195
2015-03-27 15:40:03.636 12150 INFO congress.dse.deepsix [-] ceilometer:: polling
2015-03-27 15:40:03.636 12150 DEBUG congress.datasources.ceilometer_driver [-] Ceilometer grabbing meters update_from_datasource /opt/stack/congress/congress/datasources/ceilometer_driver.py:165
2015-03-27 15:40:03.641 12150 DEBUG keystoneclient.session [-] RESP: [200] content-length: 9938 x-subject-token: {SHA1}a908e3dd85fe63f2e614d9dae2f5222c045508a4 vary: X-Auth-Token keep-alive: timeout=5, max=100 server: Apache/2.4.7 (Ubuntu) connection: Keep-Alive date: Fri, 27 Mar 2015 14:40:03 GMT content-type: application/json x-openstack-request-id: req-ebf471a0-9233-473b-afc6-f67490968876
RESP BODY: {"token": {"methods": ["password", "token"], "roles": [{"id": "91c94f8d6693417f9840541e7ebd1333", "name": "admin"}], "expires_at": "2015-03-27T15:40:03.000000Z", "project": {"domain": {"id": "default", "name": "Default"}, "id": "060f46bc030c411481935e5cfb2c5c70", "name": "admin"}, "catalog": "<removed>", "extras": {}, "user": {"domain": {"id": "default", "name": "Default"}, "id": "81db037a8aa247aaacf27098ff5e4005", "name": "admin"}, "audit_ids": ["BHYoICCITye8voUvnKhWYQ"], "issued_at": "2015-03-27T14:40:03.543122"}}
_http_log_response /usr/local/lib/python2.7/dist-packages/keystoneclient/session.py:224
2015-03-27 15:40:03.643 12150 DEBUG congress.api.application [req-0f0f9281-0128-4acc-be88-f93344621884 None] Handling request 'POST /v1/policies/murano_system/rules' with CollectionHandler(/v1/policies/(?P<policy_id>[^/]+)/rules$) __call__ /opt/stack/congress/congress/api/application.py:45
2015-03-27 15:40:03.645 12150 DEBUG congress.dse.deepsix [req-0f0f9281-0128-4acc-be88-f93344621884 None] engine:: process_policy_update [<congress.datalog.compile.Event object at 0x7ff1b1c2d9b0>] log_debug /opt/stack/congress/congress/dse/deepsix.py:565
2015-03-27 15:40:03.648 12150 DEBUG congress.datalog.base [req-0f0f9281-0128-4acc-be88-f93344621884 None] RT : Updating with <congress.datalog.utility.iterstr object at 0x7ff1b0830f50> log /opt/stack/congress/congress/datalog/base.py:46
2015-03-27 15:40:03.651 12150 DEBUG congress.dse.deepsix [req-0f0f9281-0128-4acc-be88-f93344621884 None] engine:: Tables:: Old: set([u'predeploy_errors', u'murano:parent_types', u'keystone:tenants', u'tenantName', u'allowedApp', u'objName', u'murano:objects', u'murano:properties', u'concat']), new: set([u'predeploy_errors', u'murano:parent_types', u'keystone:tenants', u'tenantName', u'allowedApp', u'objName', u'murano:objects', u'murano:properties', u'concat']), add: set([]), rem: set([]) log_debug /opt/stack/congress/congress/dse/deepsix.py:565
2015-03-27 15:40:03.651 12150 DEBUG congress.api.application [req-0f0f9281-0128-4acc-be88-f93344621884 None] ApiApplication: found DataModelException Rule already exists __call__ /opt/stack/congress/congress/api/application.py:52
2015-03-27 15:40:03.652 12150 INFO eventlet.wsgi.server [req-0f0f9281-0128-4acc-be88-f93344621884 None] 16.60.142.48 - - [27/Mar/2015 15:40:03] "POST /v1/policies/murano_system/rules HTTP/1.1" 409 305 0.098213
2015-03-27 15:40:03.689 12150 DEBUG congress.datasources.ceilometer_driver [-] Ceilometer grabbing alarms update_from_datasource /opt/stack/congress/congress/datasources/ceilometer_driver.py:172
2015-03-27 15:40:03.699 12150 DEBUG congress.datasources.ceilometer_driver [-] Ceilometer grabbing events update_from_datasource /opt/stack/congress/congress/datasources/ceilometer_driver.py:179
2015-03-27 15:40:03.707 12150 DEBUG congress.dse.deepsix [-] nova:: publishing to dataindex flavors with data set([('3', 'm1.medium', 2, 4096, 40, 0, 1.0), ('2', 'm1.small', 1, 2048, 20, 0, 1.0), ('5', 'm1.xlarge', 8, 16384, 160, 0, 1.0), ('1', 'm1.tiny', 1, 512, 1, 0, 1.0), ('4', 'm1.large', 4, 8192, 80, 0, 1.0)]) log_debug /opt/stack/congress/congress/dse/deepsix.py:565
2015-03-27 15:40:03.707 12150 DEBUG congress.dse.deepsix [-] nova:: pushing dataindex flavors to subscribers {} and requesters {} log_debug /opt/stack/congress/congress/dse/deepsix.py:565
2015-03-27 15:40:03.707 12150 DEBUG congress.dse.deepsix [-] nova:: no requesters/subscribers; not sending log_debug /opt/stack/congress/congress/dse/deepsix.py:565
2015-03-27 15:40:03.708 12150 DEBUG congress.dse.deepsix [-] nova:: publishing to dataindex floating_IPs with data set([]) log_debug /opt/stack/congress/congress/dse/deepsix.py:565
2015-03-27 15:40:03.708 12150 DEBUG congress.dse.deepsix [-] nova:: pushing dataindex floating_IPs to subscribers {} and requesters {} log_debug /opt/stack/congress/congress/dse/deepsix.py:565
2015-03-27 15:40:03.708 12150 DEBUG congress.dse.deepsix [-] nova:: no requesters/subscribers; not sending log_debug /opt/stack/congress/congress/dse/deepsix.py:565
2015-03-27 15:40:03.708 12150 DEBUG congress.dse.deepsix [-] nova:: publishing to dataindex servers with data set([('c9eb39d0-b054-4b81-8096-77a1907b4bcc', 'murano-eroooi7rngrwg1-jmkpei7rngp062-x3nevkgvp32t', 'b94351ca8b5775c34f69e4e1abe4a2e914d04b1f29eb6a18ca439473', 'ACTIVE', '9c386ec62eff4e9098f254365ad4e646', '81db037a8aa247aaacf27098ff5e4005', 'e294a943-ebd8-4685-876a-124fcb33c0ef', '3')]) log_debug /opt/stack/congress/congress/dse/deepsix.py:565
2015-03-27 15:40:03.708 12150 DEBUG congress.dse.deepsix [-] nova:: pushing dataindex servers to subscribers {} and requesters {} log_debug /opt/stack/congress/congress/dse/deepsix.py:565
It seems that the root cause of the problem is inserting a rule (without a body) that has a different number of columns for a table than other facts that already exist. This causes an IndexError when inserting the rule, which inserts the rule into the policy engine but not into the database. Two fixes are needed:
1) We need to be more careful to ensure that we don't enter into this inconsistent state where the policy engine has a different collection of data than the database.
2) We need to catch the error (wrong number of columns) when inserting rules. Because schemas need not be declared before a rule is inserted, we need to keep track of the number of args for every table occurring in the rules and check that the number of args for each new rule is consistent with that info (a kind of 'inferred schema'). This requires refcounting so that we know when to delete one of these inferred schemas.