Open Stack

You should respond to the list so other users can try to support you.

So nova is trying to live snapshot the instance:

> 2022-06-12 16:25:55.603 7 INFO nova.compute.manager  
> [req-5ecfdf74-7cf3-481a-aa12-140deae202f7  
> 4dbffaa9c14e401c8c210e23ebe0ab7b ef940663426b4c87a751afaf13b758e0 -  
> default default] [instance: 25c8d676-e20a-4238-a45c-d51daa62b941]  
> instance snapshotting
> [...] [instance: 25c8d676-e20a-4238-a45c-d51daa62b941] Beginning  
> live snapshot process

But I don't see any 'rbd snap create' command. Either the rbd image  
doesn't support it or there is some setting to keep all rbd images  
"flat". Can you check any relevant configs you might have in nova?  
Also can you show the output of 'rbd info  
<pool>/25c8d676-e20a-4238-a45c-d51daa62b941_disk' ? Then to test if  
the underlying rbd functions work as expected you could try to create  
a live snapshot manually:

rbd snap create <pool>/25c8d676-e20a-4238-a45c-d51daa62b941_disk at test-snap

And paste any relevant output here.

Zitat von Parsa Aminian <p.aminian.server at gmail.com>:

> Its not working for any instances and all of them are paused . I enable
> debug logs please check the logs :
>
> 2022-06-12 16:16:13.478 7 DEBUG nova.compute.manager
> [req-2ecf34c3-72e7-4f33-89cb-9b250cd6d223 - - - - -] Triggering sync for
> uuid 25c8d676-e20a-4238-a45c-d51daa62b941 _sync_power_states
> /var/lib/kolla/venv/lib/python3.6/site-packages/nova/compute/manager.py:9693
> 2022-06-12 16:16:13.506 7 DEBUG oslo_concurrency.lockutils [-] Lock
> "25c8d676-e20a-4238-a45c-d51daa62b941" acquired by
> "nova.compute.manager.ComputeManager._sync_power_states.<locals>._sync.<locals>.query_driver_power_state_and_sync"
> :: waited 0.000s inner
> /var/lib/kolla/venv/lib/python3.6/site-packages/oslo_concurrency/lockutils.py:359
> 2022-06-12 16:16:43.562 7 DEBUG nova.compute.resource_tracker
> [req-2ecf34c3-72e7-4f33-89cb-9b250cd6d223 - - - - -] Instance
> 25c8d676-e20a-4238-a45c-d51daa62b941 actively managed on this compute host
> and has allocations in placement: {'resources': {'VCPU': 1, 'MEMORY_MB':
> 1024, 'DISK_GB': 20}}. _remove_deleted_instances_allocations
> /var/lib/kolla/venv/lib/python3.6/site-packages/nova/compute/resource_tracker.py:1539
> 2022-06-12 16:25:55.104 7 DEBUG nova.compute.manager
> [req-5ecfdf74-7cf3-481a-aa12-140deae202f7 4dbffaa9c14e401c8c210e23ebe0ab7b
> ef940663426b4c87a751afaf13b758e0 - default default] [instance:
> 25c8d676-e20a-4238-a45c-d51daa62b941] Checking state _get_power_state
> /var/lib/kolla/venv/lib/python3.6/site-packages/nova/compute/manager.py:1569
> 2022-06-12 16:25:55.603 7 INFO nova.compute.manager
> [req-5ecfdf74-7cf3-481a-aa12-140deae202f7 4dbffaa9c14e401c8c210e23ebe0ab7b
> ef940663426b4c87a751afaf13b758e0 - default default] [instance:
> 25c8d676-e20a-4238-a45c-d51daa62b941] instance snapshotting
> 63426b4c87a751afaf13b758e0 - default default] [instance:
> 25c8d676-e20a-4238-a45c-d51daa62b941] Beginning live snapshot process
> default default] Lazy-loading 'pci_devices' on Instance uuid
> 25c8d676-e20a-4238-a45c-d51daa62b941 obj_load_attr
> /var/lib/kolla/venv/lib/python3.6/site-packages/nova/objects/instance.py:1101
> 2022-06-12 16:25:57.250 7 DEBUG nova.objects.instance
> [req-5ecfdf74-7cf3-481a-aa12-140deae202f7 4dbffaa9c14e401c8c210e23ebe0ab7b
> ef940663426b4c87a751afaf13b758e0 - default default] Lazy-loading
> 'pci_devices' on Instance uuid 25c8d676-e20a-4238-a45c-d51daa62b941
> obj_load_attr
> /var/lib/kolla/venv/lib/python3.6/site-packages/nova/objects/instance.py:1101
> 2022-06-12 16:25:57.317 7 DEBUG nova.virt.driver [-] Emitting event
> <LifecycleEvent: 1655034957.3158934, 25c8d676-e20a-4238-a45c-d51daa62b941
> => Paused> emit_event
> /var/lib/kolla/venv/lib/python3.6/site-packages/nova/virt/driver.py:1704
> 2022-06-12 16:25:57.318 7 INFO nova.compute.manager [-] [instance:
> 25c8d676-e20a-4238-a45c-d51daa62b941] VM Paused (Lifecycle Event)
> 2022-06-12 16:25:57.389 7 DEBUG nova.compute.manager
> [req-40444d74-f2fa-4569-87dd-375139938e81 - - - - -] [instance:
> 25c8d676-e20a-4238-a45c-d51daa62b941] Checking state _get_power_state
> /var/lib/kolla/venv/lib/python3.6/site-packages/nova/compute/manager.py:1569
> 2022-06-12 16:25:57.395 7 DEBUG nova.compute.manager
> [req-40444d74-f2fa-4569-87dd-375139938e81 - - - - -] [instance:
> 25c8d676-e20a-4238-a45c-d51daa62b941] Synchronizing instance power state
> after lifecycle event "Paused"; current vm_state: active, current
> task_state: image_pending_upload, current DB power_state: 1, VM
> power_state: 3 handle_lifecycle_event
> /var/lib/kolla/venv/lib/python3.6/site-packages/nova/compute/manager.py:1299
> 2022-06-12 16:25:57.487 7 INFO nova.compute.manager
> [req-40444d74-f2fa-4569-87dd-375139938e81 - - - - -] [instance:
> 25c8d676-e20a-4238-a45c-d51daa62b941] During sync_power_state the instance
> has a pending task (image_pending_upload). Skip.
> 2022-06-12 16:26:02.039 7 DEBUG oslo_concurrency.processutils
> [req-5ecfdf74-7cf3-481a-aa12-140deae202f7 4dbffaa9c14e401c8c210e23ebe0ab7b
> ef940663426b4c87a751afaf13b758e0 - default default] Running cmd
> (subprocess): qemu-img convert -t none -O raw -f raw
> rbd:vms/25c8d676-e20a-4238-a45c-d51daa62b941_disk:id=cinder:conf=/etc/ceph/ceph.conf
> /var/lib/nova/instances/snapshots/tmpv21b_i59/8717dec4c99c4ef7bac752e2a48690ad
> execute
> /var/lib/kolla/venv/lib/python3.6/site-packages/oslo_concurrency/processutils.py:384
> 2022-06-12 16:26:17.075 7 DEBUG nova.virt.driver [-] Emitting event
> <LifecycleEvent: 1655034962.0316682, 25c8d676-e20a-4238-a45c-d51daa62b941
> => Stopped> emit_event
> /var/lib/kolla/venv/lib/python3.6/site-packages/nova/virt/driver.py:1704
> INFO nova.compute.manager [-] [instance:
> 25c8d676-e20a-4238-a45c-d51daa62b941] VM Stopped (Lifecycle Event)
> DEBUG nova.compute.manager [req-f9f8cbf5-6208-4dca-aca6-48dee87f38fa - - -
> - -] [instance: 25c8d676-e20a-4238-a45c-d51daa62b941] Checking state
> _get_power_state
> /var/lib/kolla/venv/lib/python3.6/site-packages/nova/compute/manager.py:1569
> DEBUG nova.compute.manager [req-f9f8cbf5-6208-4dca-aca6-48dee87f38fa - - -
> - -] [instance: 25c8d676-e20a-4238-a45c-d51daa62b941] Synchronizing
> instance power state after lifecycle event "Stopped"; current vm_state:
> active, current task_state: image_pending_upload, current DB power_state:
> 1, VM power_state: 4 handle_lifecycle_event
> /var/lib/kolla/venv/lib/python3.6/site-packages/nova/compute/manager.py:1299
> INFO nova.compute.manager [req-f9f8cbf5-6208-4dca-aca6-48dee87f38fa - - - -
> -] [instance: 25c8d676-e20a-4238-a45c-d51daa62b941] During sync_power_state
> the instance has a pending task (image_pending_upload). Skip.
> 2022-06-12 16:26:18.539 7 DEBUG nova.compute.manager
> [req-2ecf34c3-72e7-4f33-89cb-9b250cd6d223 - - - - -] Triggering sync for
> uuid 25c8d676-e20a-4238-a45c-d51daa62b941 _sync_power_states
> /var/lib/kolla/venv/lib/python3.6/site-packages/nova/compute/manager.py:9693
> 2022-06-12 16:26:18.565 7 DEBUG oslo_concurrency.lockutils [-] Lock
> "25c8d676-e20a-4238
> -a45c-d51daa62b941" acquired by
> "nova.compute.manager.ComputeManager._sync_power_states.<locals>._sync.<locals>.query_driver_power_state_and_sync"
> :: waited 0.000s inner
> /var/lib/kolla/venv/lib/python3.6/site-packages/oslo_concurrency/lockutils.py:359
> 2022-06-12 16:26:18.566 7 INFO nova.compute.manager [-] [instance:
> 25c8d676-e20a-4238-a45c-d51daa62b941] During sync_power_state the instance
> has a pending task (image_pending_upload). Skip.
> 2022-06-12 16:26:18.566 7 DEBUG oslo_concurrency.lockutils [-] Lock
> "25c8d676-e20a-4238-a45c-d51daa62b941" released by
> "nova.compute.manager.ComputeManager._sync_power_states.<locals>._sync.<locals>.query_driver_power_state_and_sync"
> :: held 0.001s inner
> /var/lib/kolla/venv/lib/python3.6/site-packages/oslo_concurrency/lockutils.py:371
> 2022-06-12 16:26:25.769 7 DEBUG oslo_concurrency.processutils
> [req-5ecfdf74-7cf3-481a-aa12-140deae202f7 4dbffaa9c14e401c8c210e23ebe0ab7b
> ef940663426b4c87a751afaf13b758e0 - default default] CMD "qemu-img convert
> -t none -O raw -f raw
> rbd:vms/25c8d676-e20a-4238-a45c-d51daa6b941_disk:id=cinder:conf=/etc/ceph/ceph.conf
> /var/lib/nova/instances/snapshots/tmpv21b_i59/8717dec4c99c4ef7bac752e2a48690ad"
> returned: 0 in 23.730s execute
> /var/lib/kolla/venv/lib/python3.6/site-packages/oslo_concurrency/processutils.py:423
> default default] [instance: 25c8d676-e20a-4238-a45c-d51daa62b941] Snapshot
> extracted, beginning image upload
> 2022-06-12 16:26:27.981 7 DEBUG nova.virt.driver
> [req-40444d74-f2fa-4569-87dd-375139938e81 - - - - -] Emitting event
> <LifecycleEvent: 1655034987.9807608, 25c8d676-e20a-4238-a45c-d51daa62b941
> => Started> emit_event
> /var/lib/kolla/venv/lib/python3.6/site-packages/nova/virt/driver.py:1704
> 2022-06-12 16:26:27.983 7 INFO nova.compute.manager
> [req-40444d74-f2fa-4569-87dd-375139938e81 - - - - -] [instance:
> 25c8d676-e20a-4238-a45c-d51daa62b941] VM Started (Lifecycle Event)
> [instance: 25c8d676-e20a-4238-a45c-d51daa62b941] Checking state
> _get_power_state
> /var/lib/kolla/venv/lib/python3.6/site-packages/nova/compute/manager.py:1569
> 25c8d676-e20a-4238-a45c-d51daa62b941] Synchronizing instance power state
> after lifecycle event "Started"; current vm_state: active, current
> task_state: image_pending_upload, current DB power_state: 1, VM
> power_state: 1 handle_lifecycle_event
> /var/lib/kolla/venv/lib/python3.6/site-packages/nova/compute/manager.py:1299
> 2022-06-12 16:26:28.173 7 INFO nova.compute.manager
> [req-40444d74-f2fa-4569-87dd-375139938e81 - - - - -] [instance:
> 25c8d676-e20a-4238-a45c-d51daa62b941] VM Resumed (Lifecycle Event
> 2022-06-12 16:29:00.859 7 DEBUG oslo_concurrency.lockutils
> [req-2ecf34c3-72e7-4f33-89cb-9b250cd6d223 - - - - -] Acquired lock
> "refresh_cache-25c8d676-e20a-4238-a45c-d51daa62b941" lock
> /var/lib/kolla/venv/lib/python3.6/site-packages/oslo_concurrency/lockutils.py:266
> 25c8d676-e20a-4238-a45c-d51daa62b941] Forcefully refreshing network info
> cache for instance _get_instance_nw_info
> /var/lib/kolla/venv/lib/python3.6/site-packages/nova/network/neutron.py:1833
> 2022-06-12 16:29:03.278 7 DEBUG nova.network.neutron
> [req-2ecf34c3-72e7-4f33-89cb-9b250cd6d223 - - - - -] [instance:
> 25c8d676-e20a-4238-a45c-d51daa62b941] Updating instance_info_cache with
> network_info: [{"id": "aa2fdd7d-ad18-4890-ad57-14bf9888d2c1", "address":
> "fa:16:3e:ca:00:d9", "network": {"id":
> "b86c8304-a9bd-4b39-b7fc-f70ffe76f2a8", "bridge": "br-int", "label":
> "External_Network", "subnets": [{"cidr": "141.11.42.0/24", "dns":
> [{"address": "8.8.8.8", "type": "dns", "version": 4, "meta": {}},
> {"address": "217.218.127.127", "type": "dns", "version": 4, "meta": {}}],
> "gateway": {"address": "141.11.42.1", "type": "gateway", "version": 4,
> "meta": {}}, "ips": [{"address": "141.11.42.37", "type": "fixed",
> "version": 4, "meta": {}, "floating_ips": []}], "routes": [], "version": 4,
> "meta": {}}], "meta": {"injected": true, "tenant_id":
> "ef940663426b4c87a751afaf13b758e0", "mtu": 1500, "physical_network":
> "physnet1", "tunneled": false}}, "type": "ovs", "details": {"connectivity":
> "l2", "port_filter": true, "ovs_hybrid_plug": true, "datapath_type":
> "system", "bridge_name": "br-int"}, "devname": "tapaa2fdd7d-ad",
> "ovs_interfaceid": "aa2fdd7d-ad18-4890-ad57-14bf9888d2c1", "qbh_params":
> null, "qbg_params": null, "active": true, "vnic_type": "normal", "profile":
> {}, "preserve_on_delete": false, "meta": {}}]
> update_instance_cache_with_nw_info
> /var/lib/kolla/venv/lib/python3.6/site-packages/nova/network/neutron.py:117
> nstance 25c8d676-e20a-4238-a45c-d51daa62b941 actively managed on this
> compute host and has allocations in placement: {'resources': {'VCPU': 1,
> 'MEMORY_MB': 1024, 'DISK_GB': 20}}. _remove_deleted_instances_allocations
> /var/lib/kolla/venv/lib/python3.6/site-packages/nova/compute/resource_tracker.py:1539
> 2022-06-12 16:33:37.595 7 INFO nova.compute.manager
> [req-5ecfdf74-7cf3-481a-aa12-140deae202f7 4dbffaa9c14e401c8c210e23ebe0ab7b
> ef940663426b4c87a751afaf13b758e0 - default default] [instance:
> 25c8d676-e20a-4238-a45c-d51daa62b941] Took 461.98 seconds to snapshot the
> instance on the hypervisor.
> 2022-06-12 16:36:16.459 7 DEBUG nova.compute.manager
> [req-2ecf34c3-72e7-4f33-89cb-9b250cd6d223 - - - - -] Triggering sync for
> uuid 25c8d676-e20a-4238-a45c-d51daa62b941 _sync_power_states
> /var/lib/kolla/venv/lib/python3.6/site-packages/nova/compute/manager.py:9693
> Lock "25c8d676-e20a-4238-a45c-d51daa62b941" acquired by
> "nova.compute.manager.ComputeManager._sync_power_states.<locals>._sync.<locals>.query_driver_power_state_and_sync"
> :: waited 0.000s inner
> /var/lib/kolla/venv/lib/python3.6/site-packages/oslo_concurrency/lockutils.py:359
> 2022-06-12 16:37:05.365 7 DEBUG nova.compute.resource_tracker
> [req-2ecf34c3-72e7-4f33-89cb-9b250cd6d223 - - - - -] Instance
> 25c8d676-e20a-4238-a45c-d51daa62b941 actively managed on this compute host
> and has allocations in placement: {'resources': {'VCPU': 1, 'MEMORY_MB':
> 1024, 'DISK_GB': 20}}. _remove_deleted_instances_allocations
> /var/lib/kolla/venv/lib/python3.6/site-packages/nova/compute/resource_tracker.py:1539
> 2022-06-12 09:42:32.687 7 INFO nova.compute.manager
> [req-e79e4177-4712-4795-91da-853bc524fac0 93fb420b3c604d4fae408b81135b58e9
> ef940663426b4c87a751afaf13b758e0 - default default] [instance:
> 25c8d676-e20a-4238-a45c-d51daa62b941] instance snapshotting
>
> On Sun, Jun 12, 2022 at 3:36 PM Eugen Block <eblock at nde.ag> wrote:
>
>> Have you tried with debug logs? Has it worked with live snapshots
>> before for other instances or did it never work and all snapshots were
>> "cold"?
>>
>> Zitat von Parsa Aminian <p.aminian.server at gmail.com>:
>>
>> > Hi
>> > kolla-ansible victoria version with ceph backend without volume
>> >
>> > On Sun, Jun 12, 2022 at 12:45 PM Eugen Block <eblock at nde.ag> wrote:
>> >
>> >> Hi,
>> >>
>> >> can you share more details about your environment? Which openstack
>> >> version is it? What is the storage backend? In earlier releases there
>> >> was an option:
>> >>
>> >> #disable_libvirt_livesnapshot = false
>> >>
>> >> but this option has been deprecated. But if you're on an older version
>> >> that could explain it.
>> >>
>> >> Zitat von Parsa Aminian <p.aminian.server at gmail.com>:
>> >>
>> >> > When I snapshot from the instance , server will gone away and its not
>> >> > reachable until the snapshot is complete here is the logs :
>> >> > 25c8d676-e20a-4238-a45c-d51daa62b941] instance snapshotting
>> >> > 2022-06-12 09:42:34.755 7 INFO nova.compute.manager
>> >> > [req-786946b1-3d22-489c-bf4d-8b1375b09ecb - - - - -] [instance:
>> >> > 25c8d676-e20a-4238-a45c-d51daa62b941] VM Paused (Lifecycle Event)
>> >> > 2022-06-12 09:42:34.995 7 INFO nova.compute.manager
>> >> > [req-786946b1-3d22-489c-bf4d-8b1375b09ecb - - - - -] [instance:
>> >> > 25c8d676-e20a-4238-a45c-d51daa62b941] During sync_power_state the
>> >> instance
>> >> > has a pending task (image_pending_upload). Skip.
>> >> > 2022-06-12 09:42:57.749 7 INFO nova.compute.manager [-] [instance:
>> >> > 25c8d676-e20a-4238-a45c-d51daa62b941] VM Stopped (Lifecycle Event)
>> >> > 2022-06-12 09:43:06.102 7 INFO nova.virt.libvirt.driver
>> >> > [req-e79e4177-4712-4795-91da-853bc524fac0
>> >> 93fb420b3c604d4fae408b81135b58e9
>> >> > ef940663426b4c87a751afaf13b758e0 - default default] [instance:
>> >> > 25c8d676-e20a-4238-a45c-d51daa62b941] Snapshot extracted, beginning
>> image
>> >> > upload
>> >> > 2022-06-12 09:43:08.778 7 INFO nova.compute.manager
>> >> > [req-786946b1-3d22-489c-bf4d-8b1375b09ecb - - - - -] [instance:
>> >> > 25c8d676-e20a-4238-a45c-d51daa62b941] VM Started (Lifecycle Event)
>> >>
>> >>
>> >>
>> >>
>> >>
>>
>>
>>
>>
>>