Hi Karl, Do you mean try rbd-nbd map a volume from ceph to compute node? Thanks, On Mon, Aug 7, 2023 at 8:58 AM Karl Kloppenborg <kkloppenborg@rwts.com.au> wrote:

Hi Ha Noi,

From those logs it appears that the lag is in the libvirt section of the block device connecting and latching to the compute node.

If you try and rbd mount manually a drive from your ceph cluster, do you see a long delay in this as well?

Kind Regards,

--

*Karl Kloppenborg, **(BCompSc, CNCF-[KCNA, CKA, CKAD], LFCE, CompTIA Linux+ XK0-004)*

Managing Director, Invention Labs.

*From: *Ha Noi <hanoi952022@gmail.com> *Date: *Monday, 7 August 2023 at 11:38 am *To: *kkloppenborg@rwts.com.au <kkloppenborg@rwts.com.au> *Cc: *openstack-discuss@lists.openstack.org < openstack-discuss@lists.openstack.org> *Subject: *Re: [openstack][nova] Slow provision 1 instance .

Hi Karl,

The volume creation time is 10 seconds. Below is the log in nova-compute. I would like to optimize nova-compute first .

3414:2023-08-07 08:33:08.436 8 INFO nova.compute.claims [req-33bf9cfd-38c5-40c3-aceb-2c4c0bfa986c 125406d260d24c77aca1b09206825437 f64e241d000441d292b91e85138e325c - default default] [instance: c54db6fe-7bf0-4ca3-8167-20ec2763b79f] Claim successful on node compute-004 3415:2023-08-07 08:33:08.702 8 INFO nova.virt.libvirt.driver [req-33bf9cfd-38c5-40c3-aceb-2c4c0bfa986c 125406d260d24c77aca1b09206825437 f64e241d000441d292b91e85138e325c - default default] [instance: c54db6fe-7bf0-4ca3-8167-20ec2763b79f] Ignoring supplied device name: /dev/vda. Libvirt can't honour user-supplied dev names 3416:2023-08-07 08:33:08.815 8 INFO nova.virt.block_device [req-33bf9cfd-38c5-40c3-aceb-2c4c0bfa986c 125406d260d24c77aca1b09206825437 f64e241d000441d292b91e85138e325c - default default] [instance: c54db6fe-7bf0-4ca3-8167-20ec2763b79f] Booting with volume 37d1487e-9118-4231-9908-fb662b626977 at /dev/vda 3417:2023-08-07 08:33:34.269 8 INFO nova.virt.libvirt.driver [req-33bf9cfd-38c5-40c3-aceb-2c4c0bfa986c 125406d260d24c77aca1b09206825437 f64e241d000441d292b91e85138e325c - default default] [instance: c54db6fe-7bf0-4ca3-8167-20ec2763b79f] Creating image 3418:2023-08-07 08:33:35.967 8 INFO os_vif [req-33bf9cfd-38c5-40c3-aceb-2c4c0bfa986c 125406d260d24c77aca1b09206825437 f64e241d000441d292b91e85138e325c - default default] Successfully plugged vif VIFBridge(active=False,address=fa:16:3e:1e:06:ae,bridge_name='qbr2ea5e4e0-a9',has_traffic_filtering=True,id=2ea5e4e0-a934-404d-ac4c-a4deadf2aa73,network=Network(a4e1151a-9671-4fb6-b620-66b80d7dce8d),plugin='ovs',port_profile=VIFPortProfileOpenVSwitch,preserve_on_delete=True,vif_name='tap2ea5e4e0-a9') 3419:2023-08-07 08:33:37.763 8 INFO os_vif [req-33bf9cfd-38c5-40c3-aceb-2c4c0bfa986c 125406d260d24c77aca1b09206825437 f64e241d000441d292b91e85138e325c - default default] Successfully plugged vif VIFBridge(active=False,address=fa:16:3e:b0:e6:12,bridge_name='qbre636e020-ec',has_traffic_filtering=True,id=e636e020-ec99-47d4-bad3-9c87c65e080f,network=Network(5f7989ab-cb9d-493b-a8c5-edf688782f81),plugin='ovs',port_profile=VIFPortProfileOpenVSwitch,preserve_on_delete=True,vif_name='tape636e020-ec') 3425:2023-08-07 08:33:45.725 8 INFO nova.compute.manager [req-33bf9cfd-38c5-40c3-aceb-2c4c0bfa986c 125406d260d24c77aca1b09206825437 f64e241d000441d292b91e85138e325c - default default] [instance: c54db6fe-7bf0-4ca3-8167-20ec2763b79f] Took 11.46 seconds to spawn the instance on the hypervisor. 3459:2023-08-07 08:34:02.909 8 INFO nova.compute.manager [req-33bf9cfd-38c5-40c3-aceb-2c4c0bfa986c 125406d260d24c77aca1b09206825437 f64e241d000441d292b91e85138e325c - default default] [instance: c54db6fe-7bf0-4ca3-8167-20ec2763b79f] Took 61.40 seconds to build instance.

As you can see, the first log, instance was claimed on node compute 004 at 08:33:08, Then it takes 1 minute (04:34:02) to build instance.

Thanks

On Fri, Aug 4, 2023 at 10:25 PM Ha Noi <hanoi952022@gmail.com> wrote:

Hi everyone,

We have a openstack with one region and more than 100 compute nodes. We are using ceph for block storage.

I don't know why my instance was provisioned too slow: more than 1 minutes.

Nova compute log:

Took 56.47 seconds to build instance.

So I would like to optimize and speed up instance build time.

Thanks and Best Regards

Hi Karl, time rbd-nbd --id cinder map SSD1/volume-f2ff322b-c9f4-4efe-9b6e-d80a9d0aa043_ERR /dev/nbd0 real 0m0.111s user 0m0.028s sys 0m0.005s The time mapping is quite fast. Thanks, On Mon, Aug 7, 2023 at 11:27 AM Karl Kloppenborg <kkloppenborg@rwts.com.au> wrote:

Hi Ha Noi,

Correct, try and take the same volume and directly map it on the server, see if it hangs for any period of time.

--Karl.

*From: *Ha Noi <hanoi952022@gmail.com> *Date: *Monday, 7 August 2023 at 1:11 pm *To: *Karl Kloppenborg <kkloppenborg@rwts.com.au> *Cc: *openstack-discuss@lists.openstack.org < openstack-discuss@lists.openstack.org> *Subject: *Re: [openstack][nova] Slow provision 1 instance .

Hi Karl,

Do you mean try rbd-nbd map a volume from ceph to compute node?

Thanks,

On Mon, Aug 7, 2023 at 8:58 AM Karl Kloppenborg <kkloppenborg@rwts.com.au> wrote:

Hi Ha Noi,

From those logs it appears that the lag is in the libvirt section of the block device connecting and latching to the compute node.

If you try and rbd mount manually a drive from your ceph cluster, do you see a long delay in this as well?

Kind Regards,

--

*Karl Kloppenborg, **(BCompSc, CNCF-[KCNA, CKA, CKAD], LFCE, CompTIA Linux+ XK0-004)*

Managing Director, Invention Labs.

*From: *Ha Noi <hanoi952022@gmail.com> *Date: *Monday, 7 August 2023 at 11:38 am *To: *kkloppenborg@rwts.com.au <kkloppenborg@rwts.com.au> *Cc: *openstack-discuss@lists.openstack.org < openstack-discuss@lists.openstack.org> *Subject: *Re: [openstack][nova] Slow provision 1 instance .

Hi Karl,

The volume creation time is 10 seconds. Below is the log in nova-compute. I would like to optimize nova-compute first .

3414:2023-08-07 08:33:08.436 8 INFO nova.compute.claims [req-33bf9cfd-38c5-40c3-aceb-2c4c0bfa986c 125406d260d24c77aca1b09206825437 f64e241d000441d292b91e85138e325c - default default] [instance: c54db6fe-7bf0-4ca3-8167-20ec2763b79f] Claim successful on node compute-004 3415:2023-08-07 08:33:08.702 8 INFO nova.virt.libvirt.driver [req-33bf9cfd-38c5-40c3-aceb-2c4c0bfa986c 125406d260d24c77aca1b09206825437 f64e241d000441d292b91e85138e325c - default default] [instance: c54db6fe-7bf0-4ca3-8167-20ec2763b79f] Ignoring supplied device name: /dev/vda. Libvirt can't honour user-supplied dev names 3416:2023-08-07 08:33:08.815 8 INFO nova.virt.block_device [req-33bf9cfd-38c5-40c3-aceb-2c4c0bfa986c 125406d260d24c77aca1b09206825437 f64e241d000441d292b91e85138e325c - default default] [instance: c54db6fe-7bf0-4ca3-8167-20ec2763b79f] Booting with volume 37d1487e-9118-4231-9908-fb662b626977 at /dev/vda 3417:2023-08-07 08:33:34.269 8 INFO nova.virt.libvirt.driver [req-33bf9cfd-38c5-40c3-aceb-2c4c0bfa986c 125406d260d24c77aca1b09206825437 f64e241d000441d292b91e85138e325c - default default] [instance: c54db6fe-7bf0-4ca3-8167-20ec2763b79f] Creating image 3418:2023-08-07 08:33:35.967 8 INFO os_vif [req-33bf9cfd-38c5-40c3-aceb-2c4c0bfa986c 125406d260d24c77aca1b09206825437 f64e241d000441d292b91e85138e325c - default default] Successfully plugged vif VIFBridge(active=False,address=fa:16:3e:1e:06:ae,bridge_name='qbr2ea5e4e0-a9',has_traffic_filtering=True,id=2ea5e4e0-a934-404d-ac4c-a4deadf2aa73,network=Network(a4e1151a-9671-4fb6-b620-66b80d7dce8d),plugin='ovs',port_profile=VIFPortProfileOpenVSwitch,preserve_on_delete=True,vif_name='tap2ea5e4e0-a9') 3419:2023-08-07 08:33:37.763 8 INFO os_vif [req-33bf9cfd-38c5-40c3-aceb-2c4c0bfa986c 125406d260d24c77aca1b09206825437 f64e241d000441d292b91e85138e325c - default default] Successfully plugged vif VIFBridge(active=False,address=fa:16:3e:b0:e6:12,bridge_name='qbre636e020-ec',has_traffic_filtering=True,id=e636e020-ec99-47d4-bad3-9c87c65e080f,network=Network(5f7989ab-cb9d-493b-a8c5-edf688782f81),plugin='ovs',port_profile=VIFPortProfileOpenVSwitch,preserve_on_delete=True,vif_name='tape636e020-ec') 3425:2023-08-07 08:33:45.725 8 INFO nova.compute.manager [req-33bf9cfd-38c5-40c3-aceb-2c4c0bfa986c 125406d260d24c77aca1b09206825437 f64e241d000441d292b91e85138e325c - default default] [instance: c54db6fe-7bf0-4ca3-8167-20ec2763b79f] Took 11.46 seconds to spawn the instance on the hypervisor. 3459:2023-08-07 08:34:02.909 8 INFO nova.compute.manager [req-33bf9cfd-38c5-40c3-aceb-2c4c0bfa986c 125406d260d24c77aca1b09206825437 f64e241d000441d292b91e85138e325c - default default] [instance: c54db6fe-7bf0-4ca3-8167-20ec2763b79f] Took 61.40 seconds to build instance.

As you can see, the first log, instance was claimed on node compute 004 at 08:33:08, Then it takes 1 minute (04:34:02) to build instance.

Thanks

On Fri, Aug 4, 2023 at 10:25 PM Ha Noi <hanoi952022@gmail.com> wrote:

Hi everyone,

We have a openstack with one region and more than 100 compute nodes. We are using ceph for block storage.

I don't know why my instance was provisioned too slow: more than 1 minutes.

Nova compute log:

Took 56.47 seconds to build instance.

So I would like to optimize and speed up instance build time.

Thanks and Best Regards

Good morning Ha Noi, Okay, based on this it seems there maybe some sort of delay in Libvirt. Have you got any logs from Libvirt? Thanks, Karl. From: Ha Noi <hanoi952022@gmail.com> Date: Monday, 7 August 2023 at 6:57 pm To: Karl Kloppenborg <kkloppenborg@rwts.com.au> Cc: openstack-discuss@lists.openstack.org <openstack-discuss@lists.openstack.org> Subject: Re: [openstack][nova] Slow provision 1 instance . Hi Karl, time rbd-nbd --id cinder map SSD1/volume-f2ff322b-c9f4-4efe-9b6e-d80a9d0aa043_ERR /dev/nbd0 real 0m0.111s user 0m0.028s sys 0m0.005s The time mapping is quite fast. Thanks, On Mon, Aug 7, 2023 at 11:27 AM Karl Kloppenborg <kkloppenborg@rwts.com.au<mailto:kkloppenborg@rwts.com.au>> wrote: Hi Ha Noi, Correct, try and take the same volume and directly map it on the server, see if it hangs for any period of time. --Karl. From: Ha Noi <hanoi952022@gmail.com<mailto:hanoi952022@gmail.com>> Date: Monday, 7 August 2023 at 1:11 pm To: Karl Kloppenborg <kkloppenborg@rwts.com.au<mailto:kkloppenborg@rwts.com.au>> Cc: openstack-discuss@lists.openstack.org<mailto:openstack-discuss@lists.openstack.org> <openstack-discuss@lists.openstack.org<mailto:openstack-discuss@lists.openstack.org>> Subject: Re: [openstack][nova] Slow provision 1 instance . Hi Karl, Do you mean try rbd-nbd map a volume from ceph to compute node? Thanks, On Mon, Aug 7, 2023 at 8:58 AM Karl Kloppenborg <kkloppenborg@rwts.com.au<mailto:kkloppenborg@rwts.com.au>> wrote: Hi Ha Noi, From those logs it appears that the lag is in the libvirt section of the block device connecting and latching to the compute node. If you try and rbd mount manually a drive from your ceph cluster, do you see a long delay in this as well? Kind Regards, -- Karl Kloppenborg, (BCompSc, CNCF-[KCNA, CKA, CKAD], LFCE, CompTIA Linux+ XK0-004) Managing Director, Invention Labs. From: Ha Noi <hanoi952022@gmail.com<mailto:hanoi952022@gmail.com>> Date: Monday, 7 August 2023 at 11:38 am To: kkloppenborg@rwts.com.au<mailto:kkloppenborg@rwts.com.au> <kkloppenborg@rwts.com.au<mailto:kkloppenborg@rwts.com.au>> Cc: openstack-discuss@lists.openstack.org<mailto:openstack-discuss@lists.openstack.org> <openstack-discuss@lists.openstack.org<mailto:openstack-discuss@lists.openstack.org>> Subject: Re: [openstack][nova] Slow provision 1 instance . Hi Karl, The volume creation time is 10 seconds. Below is the log in nova-compute. I would like to optimize nova-compute first . 3414:2023-08-07 08:33:08.436 8 INFO nova.compute.claims [req-33bf9cfd-38c5-40c3-aceb-2c4c0bfa986c 125406d260d24c77aca1b09206825437 f64e241d000441d292b91e85138e325c - default default] [instance: c54db6fe-7bf0-4ca3-8167-20ec2763b79f] Claim successful on node compute-004 3415:2023-08-07 08:33:08.702 8 INFO nova.virt.libvirt.driver [req-33bf9cfd-38c5-40c3-aceb-2c4c0bfa986c 125406d260d24c77aca1b09206825437 f64e241d000441d292b91e85138e325c - default default] [instance: c54db6fe-7bf0-4ca3-8167-20ec2763b79f] Ignoring supplied device name: /dev/vda. Libvirt can't honour user-supplied dev names 3416:2023-08-07 08:33:08.815 8 INFO nova.virt.block_device [req-33bf9cfd-38c5-40c3-aceb-2c4c0bfa986c 125406d260d24c77aca1b09206825437 f64e241d000441d292b91e85138e325c - default default] [instance: c54db6fe-7bf0-4ca3-8167-20ec2763b79f] Booting with volume 37d1487e-9118-4231-9908-fb662b626977 at /dev/vda 3417:2023-08-07 08:33:34.269 8 INFO nova.virt.libvirt.driver [req-33bf9cfd-38c5-40c3-aceb-2c4c0bfa986c 125406d260d24c77aca1b09206825437 f64e241d000441d292b91e85138e325c - default default] [instance: c54db6fe-7bf0-4ca3-8167-20ec2763b79f] Creating image 3418:2023-08-07 08:33:35.967 8 INFO os_vif [req-33bf9cfd-38c5-40c3-aceb-2c4c0bfa986c 125406d260d24c77aca1b09206825437 f64e241d000441d292b91e85138e325c - default default] Successfully plugged vif VIFBridge(active=False,address=fa:16:3e:1e:06:ae,bridge_name='qbr2ea5e4e0-a9',has_traffic_filtering=True,id=2ea5e4e0-a934-404d-ac4c-a4deadf2aa73,network=Network(a4e1151a-9671-4fb6-b620-66b80d7dce8d),plugin='ovs',port_profile=VIFPortProfileOpenVSwitch,preserve_on_delete=True,vif_name='tap2ea5e4e0-a9') 3419:2023-08-07 08:33:37.763 8 INFO os_vif [req-33bf9cfd-38c5-40c3-aceb-2c4c0bfa986c 125406d260d24c77aca1b09206825437 f64e241d000441d292b91e85138e325c - default default] Successfully plugged vif VIFBridge(active=False,address=fa:16:3e:b0:e6:12,bridge_name='qbre636e020-ec',has_traffic_filtering=True,id=e636e020-ec99-47d4-bad3-9c87c65e080f,network=Network(5f7989ab-cb9d-493b-a8c5-edf688782f81),plugin='ovs',port_profile=VIFPortProfileOpenVSwitch,preserve_on_delete=True,vif_name='tape636e020-ec') 3425:2023-08-07 08:33:45.725 8 INFO nova.compute.manager [req-33bf9cfd-38c5-40c3-aceb-2c4c0bfa986c 125406d260d24c77aca1b09206825437 f64e241d000441d292b91e85138e325c - default default] [instance: c54db6fe-7bf0-4ca3-8167-20ec2763b79f] Took 11.46 seconds to spawn the instance on the hypervisor. 3459:2023-08-07 08:34:02.909 8 INFO nova.compute.manager [req-33bf9cfd-38c5-40c3-aceb-2c4c0bfa986c 125406d260d24c77aca1b09206825437 f64e241d000441d292b91e85138e325c - default default] [instance: c54db6fe-7bf0-4ca3-8167-20ec2763b79f] Took 61.40 seconds to build instance. As you can see, the first log, instance was claimed on node compute 004 at 08:33:08, Then it takes 1 minute (04:34:02) to build instance. Thanks On Fri, Aug 4, 2023 at 10:25 PM Ha Noi <hanoi952022@gmail.com<mailto:hanoi952022@gmail.com>> wrote: Hi everyone, We have a openstack with one region and more than 100 compute nodes. We are using ceph for block storage. I don't know why my instance was provisioned too slow: more than 1 minutes. Nova compute log: Took 56.47 seconds to build instance. So I would like to optimize and speed up instance build time. Thanks and Best Regards