Making provisioning faster?


#1

Hi,

When eg. cloning VM from template (done service catalog item) using vmware, is there any way to speed up things. MiQ is doing “nothing” at time to time, if you check automation log. eg: here’s a snapshot of a automate.log and there’s over 25 seconds with nothing.

[----] I, [2015-03-17T14:33:25.632783 #2033:9383b74] INFO – : Q-task_id([service_template_provision_task_292]) ===== EVM Automate Method: <update_serviceprovision_status> Ended
[----] I, [2015-03-17T14:33:25.641186 #2033:9a3814] INFO – : Q-task_id([service_template_provision_task_292]) <AEMethod [TEST/Service/Provision
ing/StateMachines/ServiceProvision_Template/update_serviceprovision_status]> Ending
[----] I, [2015-03-17T14:33:25.641304 #2033:9a3814] INFO – : Q-task_id([service_template_provision_task_292]) Method exited with rc=MIQ_OK
[----] I, [2015-03-17T14:33:51.063538 #15144:8bb80c] INFO – : Q-task_id([service_template_provision_task_292]) Instantiating [/TEST/Service/Pro
visioning/StateMachines/ServiceProvision_Template/CatalogItemInitialization?MiqServer%3A%3Amiq_server=2&ServiceTemplateProvisionTask%3A%3Aservic
e_template_provision_task=292&User%3A%3Auser=2&ae_state=checkprovisioned&ae_state_retries=1&ae_state_started=2015-03-17%2014%3A33%3A24%20UTC&dia
log_cpu=4&dialog_disksize=40&dialog_environment=test&dialog_hostname=tonirest123&dialog_memory=8192&object_name=CatalogItemInitialization&reques
t=clone_to_service&vmdb_object_type=service_template_provision_task#create]
[----] I, [2015-03-17T14:33:51.553895 #15144:8bb80c] INFO – : Q-task_id([service_template_provision_task_292]) Processing State=[checkprovisio
ned]
[----] I, [2015-03-17T14:33:51.554700 #15144:8bb80c] INFO – : Q-task_id([service_template_provision_task_292]) Following Relationship [miqaedb
:/Service/Provisioning/StateMachines/Methods/CheckProvisioned#create]


other one on same provisioning request

[----] I, [2015-03-17T14:33:57.885166 #15144:8bb80c] INFO – : Q-task_id([service_template_provision_task_293]) <AEMethod [ManageIQ/Service/Provisioning/StateMachines/ServiceProvision_Template/update_serviceprovision_status]> Ending
[----] I, [2015-03-17T14:33:57.885279 #15144:8bb80c] INFO – : Q-task_id([service_template_provision_task_293]) Method exited with rc=MIQ_OK
[----] I, [2015-03-17T14:34:23.133814 #15144:8bb80c] INFO – : Q-task_id([service_template_provision_task_292]) Instantiating [/TEST/Service/Provisioning/StateMachines/ServiceProvision_Template/CatalogItemInitialization?MiqServer%3A%3Amiq_server=2&ServiceTemplateProvisionTask%3A%3Aservice_template_provision_task=292&User%3A%3Auser=2&ae_state=checkprovisioned&ae_state_retries=2&ae_state_started=2015-03-17%2014%3A33%3A24%20UTC&dialog_cpu=4&dialog_disksize=40&dialog_environment=test&dialog_hostname=tonirest123&dialog_memory=8192&object_name=CatalogItemInitialization&request=clone_to_service&vmdb_object_type=service_template_provision_task#create]
[----] I, [2015-03-17T14:34:23.450904 #15144:8bb80c] INFO – : Q-task_id([service_template_provision_task_292]) Processing State=[checkprovisioned]
[----] I, [2015-03-17T14:34:23.452832 #15144:8bb80c] INFO – : Q-task_id([service_template_provision_task_292]) Following Relationship [miqaedb:/Service/Provisioning/StateMachines/Methods/CheckProvisioned#create]

thanks.


#2

@tonimaatta Just guessing (I don’t have the exact insight in which worker’s context are the AE methods run), but maybe you just need to increase the number of workers (probably Generic) because there’s something happening in the background meanwhile?

You can try it if it works, if not, some devel might pop in here and advise.

Milan Falešník, QE


#3

The state machine is in the checkprovisioned state (ae_state=checkprovisioned) which should be running the Service/Provisioning/StateMachines/Methods/check_provisioned. In that method you can reduce the retry interval.

Default:

when 'retry'
  $evm.root['ae_result']         = 'retry'
  $evm.root['ae_retry_interval'] = '1.minute'

Keep in mind that the checkprovisioned state defines the Max Retries value (default = 100). If you reduce the retry_interval the total time the state will retry before failing will be reduced so you may want to increase the Max Retires count to compensate.

The VM provisioning state machine has the same logic so you may want to try adjusting the same values there.


#4

Yeah I’ve noticed those retry_intervals, but those doesn’t affect that much. on both cases provisioning takes approx 10-15mins, which is quite long since VM cloning takes only 12 seconds. That’s why I’m wondering what happens on provisioning.

And this is quite much testing environment I’m playing with, so it shouldn’t be that there’s a lot of stuff going on.

Just wondering if how fast you guys can provision a VM to vSphere environment with cloning a VM.

Speed is good and there’s no reason to make it fast – eg. you can get a VM from AWS pretty quickly.


#5

To move beyond the check_provisioned state the code needs to have collected the VM through an inventory refresh so the object is in the system for post-provision processing. The provision logic requests a refresh so I would not expect it to take that long to identify the new VM in the system.

It would be helpful to know from the logs when the VM was added to inventory and when the provisioning state-machine determines that and moves past the check_provisioned state.

You will be able to determine when the VM was added by looking for the log message: “Creating Vm [<vm_name>]” or using the “created_on” column of the VM.


#6

Here’s the log if you want to take a look.

first cap is 06:17:24 to 06:17:35
second 06:17:39 to 06:18:05

… and so on.

http://pastebin.com/r2r85wdB


#7

Any conclusions?