VersionsCallbackNotFound exception when using QoS

[John Kasperski]

VersionsCallbackNotFound exception occurred in neutron-server running networking-ovn when trying to enable QoS with the following commands:

$ neutron qos-policy-create bw-limiter

$ neutron qos-bandwidth-limit-rule-create bw-limiter --max-kbps 3000 --max-burst-kbps 300

Note: This exception occurred when running core plugin or ML2 mech driver.

2016-05-20 09:41:36.789 27596 DEBUG oslo_policy.policy [req-0fe76c74-76a6-43b3-8f5b-4d85a65aec7b admin -] Reloaded policy file: /etc/neutron/policy.json _load_policy_file /usr/local/lib/python2.7/dist-packages/oslo_policy/policy.py:520
2016-05-20 09:41:36.954 27596 INFO neutron.wsgi [req-0fe76c74-76a6-43b3-8f5b-4d85a65aec7b admin -] 192.168.56.10 - - [20/May/2016 09:41:36] "GET /v2.0/qos/policies.json?fields=id&name=bw-limiter HTTP/1.1" 200 260 0.368297
2016-05-20 09:41:37.031 27596 DEBUG neutron.api.v2.base [req-c50967a6-838f-4da8-adab-9a44e7c7c207 admin -] Request body: {u'bandwidth_limit_rule': {u'max_kbps': u'3000', u'max_burst_kbps': u'300'}} prepare_request_body /opt/stack/neutron/neutron/api/v2/base.py:658
2016-05-20 09:41:37.031 27596 DEBUG neutron.api.v2.base [req-c50967a6-838f-4da8-adab-9a44e7c7c207 admin -] Unknown quota resources ['bandwidth_limit_rule']. _create /opt/stack/neutron/neutron/api/v2/base.py:460
2016-05-20 09:41:37.056 27596 DEBUG neutron.api.rpc.handlers.resources_rpc [req-c50967a6-838f-4da8-adab-9a44e7c7c207 admin -] neutron.api.rpc.handlers.resources_rpc.ResourcesPushRpcApi method push called with arguments (<neutron.context.Context object at 0x7f7800152f50>, QosPolicy(description='',id=dbee9581-44a5-4889-bd06-9193eb08c10d,name='bw-limiter',rules=[QosRule(7317f86e-bacb-4c6c-9221-66e2f9d9309d)],shared=False,tenant_id=7c291c3d9d1a45dd89c8c80c7f5f12b0), 'updated') {} wrapper /usr/local/lib/python2.7/dist-packages/oslo_log/helpers.py:47
2016-05-20 09:41:37.056 27596 ERROR neutron.api.v2.resource [req-c50967a6-838f-4da8-adab-9a44e7c7c207 admin -] create failed
2016-05-20 09:41:37.056 27596 ERROR neutron.api.v2.resource Traceback (most recent call last):
2016-05-20 09:41:37.056 27596 ERROR neutron.api.v2.resource File "/opt/stack/neutron/neutron/api/v2/resource.py", line 84, in resource
2016-05-20 09:41:37.056 27596 ERROR neutron.api.v2.resource result = method(request=request, **args)
2016-05-20 09:41:37.056 27596 ERROR neutron.api.v2.resource File "/opt/stack/neutron/neutron/api/v2/base.py", line 412, in create
2016-05-20 09:41:37.056 27596 ERROR neutron.api.v2.resource return self._create(request, body, **kwargs)
2016-05-20 09:41:37.056 27596 ERROR neutron.api.v2.resource File "/usr/local/lib/python2.7/dist-packages/oslo_db/api.py", line 148, in wrapper
2016-05-20 09:41:37.056 27596 ERROR neutron.api.v2.resource ectxt.value = e.inner_exc
2016-05-20 09:41:37.056 27596 ERROR neutron.api.v2.resource File "/usr/local/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 221, in __exit__
2016-05-20 09:41:37.056 27596 ERROR neutron.api.v2.resource self.force_reraise()
2016-05-20 09:41:37.056 27596 ERROR neutron.api.v2.resource File "/usr/local/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 197, in force_reraise
2016-05-20 09:41:37.056 27596 ERROR neutron.api.v2.resource six.reraise(self.type_, self.value, self.tb)
2016-05-20 09:41:37.056 27596 ERROR neutron.api.v2.resource File "/usr/local/lib/python2.7/dist-packages/oslo_db/api.py", line 138, in wrapper
2016-05-20 09:41:37.056 27596 ERROR neutron.api.v2.resource return f(*args, **kwargs)
2016-05-20 09:41:37.056 27596 ERROR neutron.api.v2.resource File "/opt/stack/neutron/neutron/api/v2/base.py", line 523, in _create
2016-05-20 09:41:37.056 27596 ERROR neutron.api.v2.resource obj = do_create(body)
2016-05-20 09:41:37.056 27596 ERROR neutron.api.v2.resource File "/opt/stack/neutron/neutron/api/v2/base.py", line 505, in do_create
2016-05-20 09:41:37.056 27596 ERROR neutron.api.v2.resource request.context, reservation.reservation_id)
2016-05-20 09:41:37.056 27596 ERROR neutron.api.v2.resource File "/usr/local/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 221, in __exit__
2016-05-20 09:41:37.056 27596 ERROR neutron.api.v2.resource self.force_reraise()
2016-05-20 09:41:37.056 27596 ERROR neutron.api.v2.resource File "/usr/local/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 197, in force_reraise
2016-05-20 09:41:37.056 27596 ERROR neutron.api.v2.resource six.reraise(self.type_, self.value, self.tb)
2016-05-20 09:41:37.056 27596 ERROR neutron.api.v2.resource File "/opt/stack/neutron/neutron/api/v2/base.py", line 498, in do_create
2016-05-20 09:41:37.056 27596 ERROR neutron.api.v2.resource return obj_creator(request.context, **kwargs)
2016-05-20 09:41:37.056 27596 ERROR neutron.api.v2.resource File "/opt/stack/neutron/neutron/db/db_base_plugin_common.py", line 38, in inner
2016-05-20 09:41:37.056 27596 ERROR neutron.api.v2.resource result = f(*args, **kwargs)
2016-05-20 09:41:37.056 27596 ERROR neutron.api.v2.resource File "/opt/stack/neutron/neutron/services/qos/qos_plugin.py", line 100, in create_policy_bandwidth_limit_rule
2016-05-20 09:41:37.056 27596 ERROR neutron.api.v2.resource self.notification_driver_manager.update_policy(context, policy)
2016-05-20 09:41:37.056 27596 ERROR neutron.api.v2.resource File "/opt/stack/neutron/neutron/services/qos/notification_drivers/manager.py", line 38, in update_policy
2016-05-20 09:41:37.056 27596 ERROR neutron.api.v2.resource driver.update_policy(context, qos_policy)
2016-05-20 09:41:37.056 27596 ERROR neutron.api.v2.resource File "/opt/stack/neutron/neutron/services/qos/notification_drivers/message_queue.py", line 56, in update_policy
2016-05-20 09:41:37.056 27596 ERROR neutron.api.v2.resource self.notification_api.push(context, policy, events.UPDATED)
2016-05-20 09:41:37.056 27596 ERROR neutron.api.v2.resource File "/usr/local/lib/python2.7/dist-packages/oslo_log/helpers.py", line 48, in wrapper
2016-05-20 09:41:37.056 27596 ERROR neutron.api.v2.resource return method(*args, **kwargs)
2016-05-20 09:41:37.056 27596 ERROR neutron.api.v2.resource File "/opt/stack/neutron/neutron/api/rpc/handlers/resources_rpc.py", line 195, in push
2016-05-20 09:41:37.056 27596 ERROR neutron.api.v2.resource versions = version_manager.get_resource_versions(resource_type)
2016-05-20 09:41:37.056 27596 ERROR neutron.api.v2.resource File "/opt/stack/neutron/neutron/api/rpc/callbacks/version_manager.py", line 254, in get_resource_versions
2016-05-20 09:41:37.056 27596 ERROR neutron.api.v2.resource return _get_cached_tracker().get_resource_versions(resource_type)
2016-05-20 09:41:37.056 27596 ERROR neutron.api.v2.resource File "/opt/stack/neutron/neutron/api/rpc/callbacks/version_manager.py", line 216, in get_resource_versions
2016-05-20 09:41:37.056 27596 ERROR neutron.api.v2.resource self._check_expiration()
2016-05-20 09:41:37.056 27596 ERROR neutron.api.v2.resource File "/opt/stack/neutron/neutron/api/rpc/callbacks/version_manager.py", line 209, in _check_expiration
2016-05-20 09:41:37.056 27596 ERROR neutron.api.v2.resource self._update_consumer_versions()
2016-05-20 09:41:37.056 27596 ERROR neutron.api.v2.resource File "/opt/stack/neutron/neutron/api/rpc/callbacks/version_manager.py", line 205, in _update_consumer_versions
2016-05-20 09:41:37.056 27596 ERROR neutron.api.v2.resource raise exceptions.VersionsCallbackNotFound()
2016-05-20 09:41:37.056 27596 ERROR neutron.api.v2.resource VersionsCallbackNotFound: No versions callback provided in ResourceVersionsManager
2016-05-20 09:41:37.056 27596 ERROR neutron.api.v2.resource
2016-05-20 09:41:37.067 27596 INFO neutron.wsgi [req-c50967a6-838f-4da8-adab-9a44e7c7c207 admin -] 192.168.56.10 - - [20/May/2016 09:41:37] "POST /v2.0/qos/policies/dbee9581-44a5-4889-bd06-9193eb08c10d/bandwidth_limit_rules.json HTTP/1.1" 500 357 0.113244
2016-05-20 09:41:37.622 27599 DEBUG oslo_messaging._drivers.amqpdriver [-] received message msg_id: 062c9aaa1bb14099b5c8f7abcde953f9 reply to reply_f0fd90eb408243f39bc6ef2b5fd4beae __call__ /usr/local/lib/python2.7/dist-packages/oslo_messaging/_drivers/amqpdriver.py:196

[John Kasperski (jckasper)]

neutron/api/rpc/callbacks/version_manager.py L212-214:

    def set_consumer_versions_callback(self, callback):
        self._consumer_versions_callback = callback

This is what should be setting the callback. It is invoked in only one place in the neutron code base: neutron/neutron/db/agents_db.py L179-186:

class AgentDbMixin(ext_agent.AgentPluginBase, AgentAvailabilityZoneMixin):
    """Mixin class to add agent extension to db_base_plugin_v2."""

    def __init__(self, *args, **kwargs):
        version_manager.set_consumer_versions_callback(
            self._get_agents_resource_versions)
        super(AgentDbMixin, self).__init__(*args, **kwargs)

This __init__ routine is not being called when networking-ovn is used as core plugin or when ML2 mech driver is used.

[John Kasperski (jckasper)]

Proposed patch: https://review.openstack.org/#/c/319444/

[Russell Bryant (russellb)]

Isn't there another interface for QoS integration than these rpc callbacks? Has anyone explored that? I can't remember details.

It seems really bizarre to use rpc at all here. There's nothing remote involved. We're using messaging to execute local code. Surely there's a way to avoid that ...

[Miguel Angel Ajo (mangelajo)]

Hi, yes

You should be able to implement the interface to your own driver, if you don't want to rely on RPC or RPC callbacks you need to implement this:

https://github.com/openstack/neutron/blob/master/neutron/services/qos/notification_drivers/qos_base.py

And register it via configuration, here's the setting: https://github.com/openstack/neutron/blob/master/neutron/services/qos/notification_drivers/manager.py#L19

You basically have methods to get "notified" (I know, it's a bad name) about changes in qos policies.

The default implementation is this one:
     https://github.com/openstack/neutron/blob/master/neutron/services/qos/notification_drivers/message_queue.py which, registers himself as provider for any remote agent doing a pull of a policy (what you're seeing), and also sends fanout messages with the policies as those are created, deleted or updated.

Let me know if something is unclear or if you need any help.

[vikram.choudhary (vikschw)]

FYI: https://github.com/openstack/neutron/blob/master/doc/source/devref/quality_of_service.rst#notification-driver-design

[Miguel Angel Ajo (mangelajo)]

Thanks for documenting that mr Vikram :D

[John Kasperski (jckasper)]

The VersionsCallbackNotFound exception is not limited to OVN. It will occur with OVS (and probably any ML2 plugin). I was able to recreate the exception with OVS by setting: "service_plugins = qos" in neutron.conf, restarting the neutron-server, and running the two CLI commands listed in the bug description.

[John Kasperski (jckasper)]

If the neutron.conf. "service_plugins" lists: neutron.services.l3_router.l3_router_plugin.L3RouterPlugin then AgentDbMixin __init__() routine is called and the exception does not occur.

[OpenStack Infra (hudson-openstack)]

Related fix proposed to branch: master
Review: https://review.openstack.org/322857

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/322857
Committed: https://git.openstack.org/cgit/openstack/neutron/commit/?id=1d43dd217a31c38caf8ad3a695c0c262d63bb724
Submitter: Jenkins
Branch: master

commit 1d43dd217a31c38caf8ad3a695c0c262d63bb724
Author: Miguel Angel Ajo <email address hidden>
Date: Mon May 30 10:34:05 2016 -0400

    Refactor the rpc callback version discovery mechanism

    The previous version depended on the AgentDbMixin to be loaded by
    any plugin, and also introduced an __init__ on the mixin which
    was problematic: mixins are expected to be classes which add methods
    to another class, but to implement no constructor. One of the plugins
    had one of the elements of MRO not calling to super().__init__ and
    hence not triggering this __init__ method.

    This change requires the plugins using the rpc callback mechanism
    to provide the AgentDbMixin which is used to refresh cache of known
    resource consumers (agents) and versions on demand, this way
    we make it more clear that the rpc_callback api is currently designed
    to be used with agents only, despite of its extensibility to other
    areas.

    Change-Id: Ie96b52dbe3a1f32cd4c11de8d8a5eff663fbf7f6
    Related-Bug: #1584204

[OpenStack Infra (hudson-openstack)]

Related fix proposed to branch: stable/mitaka
Review: https://review.openstack.org/327671

[OpenStack Infra (hudson-openstack)]

Change abandoned by John Kasperski (<email address hidden>) on branch: master
Review: https://review.openstack.org/319444
Reason: The original code that added logic to an __init__() routine was corrected under: https://review.openstack.org/#/c/322857/2

Now that the above patch has merged, this workaround can be abandoned.

[Richard Theis (rtheis)]

Hi John, does this bug still impact networking-ovn?

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/327671
Committed: https://git.openstack.org/cgit/openstack/neutron/commit/?id=1d18475dbd1b8375b445467b332e1a3d564f7d88
Submitter: Jenkins
Branch: stable/mitaka

commit 1d18475dbd1b8375b445467b332e1a3d564f7d88
Author: Miguel Angel Ajo <email address hidden>
Date: Mon May 30 10:34:05 2016 -0400

    Refactor the rpc callback version discovery mechanism

    The previous version depended on the AgentDbMixin to be loaded by
    any plugin, and also introduced an __init__ on the mixin which
    was problematic: mixins are expected to be classes which add methods
    to another class, but to implement no constructor. One of the plugins
    had one of the elements of MRO not calling to super().__init__ and
    hence not triggering this __init__ method.

    This change requires the plugins using the rpc callback mechanism
    to provide the AgentDbMixin which is used to refresh cache of known
    resource consumers (agents) and versions on demand, this way
    we make it more clear that the rpc_callback api is currently designed
    to be used with agents only, despite of its extensibility to other
    areas.

    Change-Id: Ie96b52dbe3a1f32cd4c11de8d8a5eff663fbf7f6
    Related-Bug: #1584204
    (cherry picked from commit 1d43dd217a31c38caf8ad3a695c0c262d63bb724)

[Ihar Hrachyshka (ihar-hrachyshka)]

I presume it's fixed now.

[Richard Theis (rtheis)]

Hi John, does this bug still impact networking-ovn?

[Richard Theis (rtheis)]

Hi John, with the neutron fixes, is networking-ovn fixed?