can't handle rpc message when cinder-volume start

[lirenke]

cinder-scheduler send a rpc message to cinder-volume which was killed just now.

Then when cinder-volume restart, it may receive the rpc message and begin to handle it before driver initialized.

Most functions in manager need to judge wether the driver has been initialized, so the rpc request would be reject. But those requests shoud be handle in fact.

The reason is, in service.py, we create consumer before manager call "init_host()", and we call "self.driver.set_initialized()" in init_host.

[wanghong (w-wanghong)]

Hi, I can reproduce this bug:
1. kill the cinder-volume process
2. create a volume using "cinder create 1" command
3. sleep abount 10 seconds, start the cinder-volume process

The cinder-volume error log is:
ERROR cinder.volume.flows.manager.create_volume [req-c5d52847-c265-4247-b94d-eec17b3f3b91 0526988ada81462d9d522b4745a8f097 7b53d02d07414469804cb6fdd5a9a774] Volume 2280b2e3-1aa6-4f1c-a02b-f945346d5c6b: create failed
2014-03-12 16:49:51.235 DEBUG taskflow.storage [-] No backend provided, not calling functor 'taskflow.storage.SingleThreadedStorage._save_task_detail' from (pid=8867) _with_connection /usr/local/lib/python2.7/dist-packages/taskflow/storage.py:88
2014-03-12 16:49:51.235 DEBUG taskflow.storage [-] No backend provided, not calling functor 'taskflow.storage.SingleThreadedStorage._save_task_detail' from (pid=8867) _with_connection /usr/local/lib/python2.7/dist-packages/taskflow/storage.py:88
2014-03-12 16:49:51.236 DEBUG taskflow.storage [-] No backend provided, not calling functor 'taskflow.storage.SingleThreadedStorage._save_flow_detail' from (pid=8867) _with_connection /usr/local/lib/python2.7/dist-packages/taskflow/storage.py:88
2014-03-12 16:49:51.236 ERROR cinder.openstack.common.rpc.amqp [req-c5d52847-c265-4247-b94d-eec17b3f3b91 0526988ada81462d9d522b4745a8f097 7b53d02d07414469804cb6fdd5a9a774] Exception during message handling
2014-03-12 16:49:51.236 TRACE cinder.openstack.common.rpc.amqp Traceback (most recent call last):
2014-03-12 16:49:51.236 TRACE cinder.openstack.common.rpc.amqp File "/opt/stack/cinder/cinder/openstack/common/rpc/amqp.py", line 462, in _process_data
2014-03-12 16:49:51.236 TRACE cinder.openstack.common.rpc.amqp **args)
2014-03-12 16:49:51.236 TRACE cinder.openstack.common.rpc.amqp File "/opt/stack/cinder/cinder/openstack/common/rpc/dispatcher.py", line 172, in dispatch
2014-03-12 16:49:51.236 TRACE cinder.openstack.common.rpc.amqp result = getattr(proxyobj, method)(ctxt, **kwargs)
2014-03-12 16:49:51.236 TRACE cinder.openstack.common.rpc.amqp File "/opt/stack/cinder/cinder/volume/manager.py", line 360, in create_volume
2014-03-12 16:49:51.236 TRACE cinder.openstack.common.rpc.amqp _run_flow()
2014-03-12 16:49:51.236 TRACE cinder.openstack.common.rpc.amqp File "/opt/stack/cinder/cinder/volume/manager.py", line 353, in _run_flow
2014-03-12 16:49:51.236 TRACE cinder.openstack.common.rpc.amqp flow_engine.run()
2014-03-12 16:49:51.236 TRACE cinder.openstack.common.rpc.amqp File "/usr/local/lib/python2.7/dist-packages/taskflow/utils/lock_utils.py", line 53, in wrapper
2014-03-12 16:49:51.236 TRACE cinder.openstack.common.rpc.amqp return f(*args, **kwargs)
2014-03-12 16:49:51.236 TRACE cinder.openstack.common.rpc.amqp File "/usr/local/lib/python2.7/dist-packages/taskflow/engines/action_engine/engine.py", line 111, in run
2014-03-12 16:49:51.236 TRACE cinder.openstack.common.rpc.amqp self._run()
2014-03-12 16:49:51.236 TRACE cinder.openstack.common.rpc.amqp File "/usr/local/lib/python2.7/dist-packages/taskflow/engines/action_engine/engine.py", line 121, in _run
2014-03-12 16:49:51.236 TRACE cinder.openstack.common.rpc.amqp self._revert(misc.Failure())
2014-03-12 16:49...

[Mike Perez (thingee)]

I followed these steps and was not able to reproduce the problem with the latest. Can you please verify if this is in an older version?

[wanghong (w-wanghong)]

Hi Mike Perez.

I have tried several times just a moment ago and reproduced. It is not 100% reproduced, but sleep 6 sceonds has the greatest probability. I used the devstack project to install openstack on ubuntu, and I make sure the code is the lastest. Could you do some tries again please?

[wanghong (w-wanghong)]

Hi Mike Perez.
Could I make this bug as confirmed?

[Mike Perez (thingee)]

It took a couple of tries, but the sleep confirmed it.

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: master
Review: https://review.openstack.org/81694

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/81694
Committed: https://git.openstack.org/cgit/openstack/cinder/commit/?id=65fa80c361f71158cc492dfc520dc4a63ccfa419
Submitter: Jenkins
Branch: master

commit 65fa80c361f71158cc492dfc520dc4a63ccfa419
Author: wanghong <email address hidden>
Date: Thu Mar 20 10:39:37 2014 +0800

    init_host should be called before RPC consumer is created

    Currently, the init_host method is called after RPC consumer is
    created. This behavior will lead to a bug that when a rpc request
    is received the manager can not handle it because the driver has not
    been initialized!

    Change-Id: Ieedba1adeb3dd98eb4ff78427fe347423c016469
    Closes-Bug: #1271568

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: stable/havana
Review: https://review.openstack.org/82041

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: stable/havana
Review: https://review.openstack.org/82408

[OpenStack Infra (hudson-openstack)]

Change abandoned by wanghong (<email address hidden>) on branch: stable/havana
Review: https://review.openstack.org/82041

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: master
Review: https://review.opendev.org/c/openstack/manila/+/787321

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.opendev.org/c/openstack/manila/+/787321
Committed: https://opendev.org/openstack/manila/commit/0339802a5d0801cda19c464a87853b60982ae011
Submitter: "Zuul (22348)"
Branch: master

commit 0339802a5d0801cda19c464a87853b60982ae011
Author: Maurice Escher <email address hidden>
Date: Wed Apr 21 10:11:03 2021 +0200

    init_host should be called before RPC consumer is created

    This change adds a new hook to Manager class called init_host_with_rpc()
    to allow services like scheduler to do something once RPC is ready.

    Copied from cinder https://opendev.org/openstack/cinder/commit/65fa80c361f71158cc492dfc520dc4a63ccfa419
    and https://opendev.org/openstack/cinder/commit/60c563f72d2d6d008fca03f0a058941f3807e1a8

    Change-Id: Iac6507a6e395c55f0fec453650009f08c2bb6563
    Closes-Bug: #1271568

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: stable/wallaby
Review: https://review.opendev.org/c/openstack/manila/+/799358

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.opendev.org/c/openstack/manila/+/799358
Committed: https://opendev.org/openstack/manila/commit/887c4bf4c041cfaafaf1c47edb9262574bbb959a
Submitter: "Zuul (22348)"
Branch: stable/wallaby

commit 887c4bf4c041cfaafaf1c47edb9262574bbb959a
Author: Maurice Escher <email address hidden>
Date: Wed Apr 21 10:11:03 2021 +0200

    init_host should be called before RPC consumer is created

    This change adds a new hook to Manager class called init_host_with_rpc()
    to allow services like scheduler to do something once RPC is ready.

    Copied from cinder https://opendev.org/openstack/cinder/commit/65fa80c361f71158cc492dfc520dc4a63ccfa419
    and https://opendev.org/openstack/cinder/commit/60c563f72d2d6d008fca03f0a058941f3807e1a8

    Change-Id: Iac6507a6e395c55f0fec453650009f08c2bb6563
    Closes-Bug: #1271568
    (cherry picked from commit 0339802a5d0801cda19c464a87853b60982ae011)

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: stable/victoria
Review: https://review.opendev.org/c/openstack/manila/+/800380

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.opendev.org/c/openstack/manila/+/800380
Committed: https://opendev.org/openstack/manila/commit/d3481f5c2645fa96c710b4298c44ba915f7d9d92
Submitter: "Zuul (22348)"
Branch: stable/victoria

commit d3481f5c2645fa96c710b4298c44ba915f7d9d92
Author: Maurice Escher <email address hidden>
Date: Wed Apr 21 10:11:03 2021 +0200

    init_host should be called before RPC consumer is created

    This change adds a new hook to Manager class called init_host_with_rpc()
    to allow services like scheduler to do something once RPC is ready.

    Copied from cinder https://opendev.org/openstack/cinder/commit/65fa80c361f71158cc492dfc520dc4a63ccfa419
    and https://opendev.org/openstack/cinder/commit/60c563f72d2d6d008fca03f0a058941f3807e1a8

    Change-Id: Iac6507a6e395c55f0fec453650009f08c2bb6563
    Closes-Bug: #1271568
    (cherry picked from commit 0339802a5d0801cda19c464a87853b60982ae011)
    (cherry picked from commit 887c4bf4c041cfaafaf1c47edb9262574bbb959a)

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: stable/ussuri
Review: https://review.opendev.org/c/openstack/manila/+/802780

[OpenStack Infra (hudson-openstack)]

This issue was fixed in the openstack/manila 13.0.0.0rc1 release candidate.

[OpenStack Infra (hudson-openstack)]

This issue was fixed in the openstack/manila 12.1.0 release.

[OpenStack Infra (hudson-openstack)]

This issue was fixed in the openstack/manila 11.1.0 release.

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.opendev.org/c/openstack/manila/+/802780
Committed: https://opendev.org/openstack/manila/commit/ad9042b2551d944aa9bf17488117419daf42e9c2
Submitter: "Zuul (22348)"
Branch: stable/ussuri

commit ad9042b2551d944aa9bf17488117419daf42e9c2
Author: Maurice Escher <email address hidden>
Date: Wed Apr 21 10:11:03 2021 +0200

    init_host should be called before RPC consumer is created

    This change adds a new hook to Manager class called init_host_with_rpc()
    to allow services like scheduler to do something once RPC is ready.

    Copied from cinder https://opendev.org/openstack/cinder/commit/65fa80c361f71158cc492dfc520dc4a63ccfa419
    and https://opendev.org/openstack/cinder/commit/60c563f72d2d6d008fca03f0a058941f3807e1a8

    Change-Id: Iac6507a6e395c55f0fec453650009f08c2bb6563
    Closes-Bug: #1271568
    (cherry picked from commit 0339802a5d0801cda19c464a87853b60982ae011)
    (cherry picked from commit 887c4bf4c041cfaafaf1c47edb9262574bbb959a)
    (cherry picked from commit d3481f5c2645fa96c710b4298c44ba915f7d9d92)

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: stable/train
Review: https://review.opendev.org/c/openstack/manila/+/821172

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.opendev.org/c/openstack/manila/+/821172
Committed: https://opendev.org/openstack/manila/commit/818ca43e78ea7d8a908cefa41970bd26f4ddea26
Submitter: "Zuul (22348)"
Branch: stable/train

commit 818ca43e78ea7d8a908cefa41970bd26f4ddea26
Author: Maurice Escher <email address hidden>
Date: Wed Apr 21 10:11:03 2021 +0200

    init_host should be called before RPC consumer is created

    This change adds a new hook to Manager class called init_host_with_rpc()
    to allow services like scheduler to do something once RPC is ready.

    Copied from cinder https://opendev.org/openstack/cinder/commit/65fa80c361f71158cc492dfc520dc4a63ccfa419
    and https://opendev.org/openstack/cinder/commit/60c563f72d2d6d008fca03f0a058941f3807e1a8

    Change-Id: Iac6507a6e395c55f0fec453650009f08c2bb6563
    Closes-Bug: #1271568
    (cherry picked from commit 0339802a5d0801cda19c464a87853b60982ae011)
    (cherry picked from commit 887c4bf4c041cfaafaf1c47edb9262574bbb959a)
    (cherry picked from commit d3481f5c2645fa96c710b4298c44ba915f7d9d92)
    (cherry picked from commit ad9042b2551d944aa9bf17488117419daf42e9c2)

[OpenStack Infra (hudson-openstack)]

This issue was fixed in the openstack/manila ussuri-eol release.

[OpenStack Infra (hudson-openstack)]

This issue was fixed in the openstack/manila train-eol release.