Hi,
when I try to create new instance or network on OpenStack from ManageIQ, they get duplicated. Request in ManageIQ shows e.g. 1 instance created but in OpenStack I see 2 of them. From nova-api.log I can see that there are 2 API create calls.
I am using gaprindashvili-2 version and it is reproducible also on gaprindashvili-1. Does anybody have similar problem? There is already an issue for that https://github.com/ManageIQ/manageiq/issues/17147 but nobody picked it up yet.
Thanks a lot.
Hello @igortiunov , I am colleague of @miso-m and we are using OpenStack Pike installed via kolla-ansible.
And here are logs from nova-api where you can see two action ‘create’ for creating Martin-test instance:
2018-03-16 15:12:05.408 35 DEBUG nova.api.openstack.wsgi [req-57d88eb9-390c-48a0-8aca-11c5a396b94c 32366f03b6db40a2a376493f281bcb42 924a712f3834478ab20af078b4214830 - default default] Action: 'create', calling method: <bound method ServersController.create of <nova.api.openstack.compute.servers.ServersController object at 0x6c05950>>, body: {"server":{"flavorRef":"1","name":"Martin-test","imageRef":"3b1196a4-cbc6-4b1c-b2bf-6e1c09b5b6f8","security_groups":[{"name":"e709cf24-f1b9-46f1-a4b9-25c74ac45a95"}],"networks":[{"uuid":"f8e79397-5691-4502-bd91-17517b3cae2f"}],"block_device_mapping_v2":[{"boot_index":0,"delete_on_termination":true,"destination_type":"local","source_type":"image","uuid":"3b1196a4-cbc6-4b1c-b2bf-6e1c09b5b6f8"}]}} _process_stack /usr/lib/python2.7/site-packages/nova/api/openstack/wsgi.py:609
2018-03-16 15:12:05.434 35 DEBUG oslo_concurrency.lockutils [req-cadc0e92-590a-4f4e-9fae-22337552bc2e - - - - -] Lock "00000000-0000-0000-0000-000000000000" acquired by "nova.context.get_or_set_cached_cell_and_set_connections" :: waited 0.000s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:270
2018-03-16 15:12:05.435 35 DEBUG oslo_concurrency.lockutils [req-cadc0e92-590a-4f4e-9fae-22337552bc2e - - - - -] Lock "00000000-0000-0000-0000-000000000000" released by "nova.context.get_or_set_cached_cell_and_set_connections" :: held 0.002s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:282
2018-03-16 15:12:05.438 35 DEBUG oslo_concurrency.lockutils [req-cadc0e92-590a-4f4e-9fae-22337552bc2e - - - - -] Lock "755ddf46-90c4-4464-94fd-655f56b9f857" acquired by "nova.context.get_or_set_cached_cell_and_set_connections" :: waited 0.000s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:270
2018-03-16 15:12:05.439 35 DEBUG oslo_concurrency.lockutils [req-cadc0e92-590a-4f4e-9fae-22337552bc2e - - - - -] Lock "755ddf46-90c4-4464-94fd-655f56b9f857" released by "nova.context.get_or_set_cached_cell_and_set_connections" :: held 0.001s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:282
2018-03-16 15:12:05.782 35 DEBUG nova.network.neutronv2.api [req-cadc0e92-590a-4f4e-9fae-22337552bc2e - - - - -] validate_networks() for [(u'f8e79397-5691-4502-bd91-17517b3cae2f', None, None, None)] validate_networks /usr/lib/python2.7/site-packages/nova/network/neutronv2/api.py:1692
2018-03-16 15:12:06.157 35 DEBUG nova.virt.hardware [req-cadc0e92-590a-4f4e-9fae-22337552bc2e - - - - -] emulator threads policy constraint: None get_emulator_threads_constraint /usr/lib/python2.7/site-packages/nova/virt/hardware.py:1287
2018-03-16 15:12:06.172 35 DEBUG nova.quota [req-cadc0e92-590a-4f4e-9fae-22337552bc2e - - - - -] Getting quotas for project 924a712f3834478ab20af078b4214830. Resources: ['metadata_items'] _get_quotas /usr/lib/python2.7/site-packages/nova/quota.py:442
2018-03-16 15:12:06.179 35 DEBUG nova.quota [req-cadc0e92-590a-4f4e-9fae-22337552bc2e - - - - -] Getting quotas for user 32366f03b6db40a2a376493f281bcb42 and project 924a712f3834478ab20af078b4214830. Resources:['metadata_items'] _get_quotas /usr/lib/python2.7/site-packages/nova/quota.py:434
2018-03-16 15:12:06.205 35 DEBUG nova.quota [req-cadc0e92-590a-4f4e-9fae-22337552bc2e - - - - -] Getting quotas for project 924a712f3834478ab20af078b4214830. Resources: ['injected_files'] _get_quotas /usr/lib/python2.7/site-packages/nova/quota.py:442
2018-03-16 15:12:06.212 35 DEBUG nova.quota [req-cadc0e92-590a-4f4e-9fae-22337552bc2e - - - - -] Getting quotas for user 32366f03b6db40a2a376493f281bcb42 and project 924a712f3834478ab20af078b4214830. Resources:['injected_files'] _get_quotas /usr/lib/python2.7/site-packages/nova/quota.py:434
2018-03-16 15:12:06.239 35 DEBUG nova.quota [req-cadc0e92-590a-4f4e-9fae-22337552bc2e - - - - -] Getting quotas for project 924a712f3834478ab20af078b4214830. Resources: ['injected_file_content_bytes', 'injected_file_path_bytes'] _get_quotas /usr/lib/python2.7/site-packages/nova/quota.py:442
2018-03-16 15:12:06.245 35 DEBUG nova.quota [req-cadc0e92-590a-4f4e-9fae-22337552bc2e - - - - -] Getting quotas for user 32366f03b6db40a2a376493f281bcb42 and project 924a712f3834478ab20af078b4214830. Resources:['injected_file_content_bytes', 'injected_file_path_bytes'] _get_quotas /usr/lib/python2.7/site-packages/nova/quota.py:434
2018-03-16 15:12:06.260 35 DEBUG oslo_concurrency.lockutils [req-57d88eb9-390c-48a0-8aca-11c5a396b94c 32366f03b6db40a2a376493f281bcb42 924a712f3834478ab20af078b4214830 - default default] Lock "00000000-0000-0000-0000-000000000000" acquired by "nova.context.get_or_set_cached_cell_and_set_connections" :: waited 0.000s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:270
2018-03-16 15:12:06.261 35 DEBUG oslo_concurrency.lockutils [req-57d88eb9-390c-48a0-8aca-11c5a396b94c 32366f03b6db40a2a376493f281bcb42 924a712f3834478ab20af078b4214830 - default default] Lock "00000000-0000-0000-0000-000000000000" released by "nova.context.get_or_set_cached_cell_and_set_connections" :: held 0.001s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:282
2018-03-16 15:12:06.262 35 DEBUG oslo_concurrency.lockutils [req-57d88eb9-390c-48a0-8aca-11c5a396b94c 32366f03b6db40a2a376493f281bcb42 924a712f3834478ab20af078b4214830 - default default] Lock "755ddf46-90c4-4464-94fd-655f56b9f857" acquired by "nova.context.get_or_set_cached_cell_and_set_connections" :: waited 0.000s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:270
2018-03-16 15:12:06.262 35 DEBUG oslo_concurrency.lockutils [req-57d88eb9-390c-48a0-8aca-11c5a396b94c 32366f03b6db40a2a376493f281bcb42 924a712f3834478ab20af078b4214830 - default default] Lock "755ddf46-90c4-4464-94fd-655f56b9f857" released by "nova.context.get_or_set_cached_cell_and_set_connections" :: held 0.001s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:282
2018-03-16 15:12:06.286 35 DEBUG nova.quota [req-57d88eb9-390c-48a0-8aca-11c5a396b94c 32366f03b6db40a2a376493f281bcb42 924a712f3834478ab20af078b4214830 - default default] Getting quotas for project 924a712f3834478ab20af078b4214830. Resources: set(['instances', 'ram', 'cores']) _get_quotas /usr/lib/python2.7/site-packages/nova/quota.py:442
2018-03-16 15:12:06.292 35 DEBUG nova.quota [req-57d88eb9-390c-48a0-8aca-11c5a396b94c 32366f03b6db40a2a376493f281bcb42 924a712f3834478ab20af078b4214830 - default default] Getting quotas for user 32366f03b6db40a2a376493f281bcb42 and project 924a712f3834478ab20af078b4214830. Resources: set(['instances', 'ram', 'cores']) _get_quotas /usr/lib/python2.7/site-packages/nova/quota.py:434
2018-03-16 15:12:06.305 35 DEBUG nova.compute.api [req-57d88eb9-390c-48a0-8aca-11c5a396b94c 32366f03b6db40a2a376493f281bcb42 924a712f3834478ab20af078b4214830 - default default] Going to run 1 instances... _provision_instances /usr/lib/python2.7/site-packages/nova/compute/api.py:891
2018-03-16 15:12:06.339 35 DEBUG nova.compute.api [req-57d88eb9-390c-48a0-8aca-11c5a396b94c 32366f03b6db40a2a376493f281bcb42 924a712f3834478ab20af078b4214830 - default default] [instance: 090e3ccd-28eb-42d8-8997-1758661c5d2a] block_device_mapping [BlockDeviceMapping(attachment_id=<?>,boot_index=0,connection_info=None,created_at=<?>,delete_on_termination=True,deleted=<?>,deleted_at=<?>,destination_type='local',device_name=None,device_type=None,disk_bus=None,guest_format=None,id=<?>,image_id='3b1196a4-cbc6-4b1c-b2bf-6e1c09b5b6f8',instance=<?>,instance_uuid=<?>,no_device=False,snapshot_id=None,source_type='image',tag=None,updated_at=<?>,volume_id=None,volume_size=None)] _bdm_validate_set_size_and_instance /usr/lib/python2.7/site-packages/nova/compute/api.py:1268
2018-03-16 15:12:06.406 35 INFO nova.osapi_compute.wsgi.server [req-57d88eb9-390c-48a0-8aca-11c5a396b94c 32366f03b6db40a2a376493f281bcb42 924a712f3834478ab20af078b4214830 - default default] 10.10.153.171,10.10.153.172 "POST /v2.1/924a712f3834478ab20af078b4214830/servers HTTP/1.1" status: 202 len: 974 time: 1.0995080
2018-03-16 15:12:06.421 35 DEBUG nova.api.openstack.wsgi [req-28626792-67c9-4a44-a446-57cf2fcd9ba8 32366f03b6db40a2a376493f281bcb42 924a712f3834478ab20af078b4214830 - default default] Action: 'create', calling method: <bound method ServersController.create of <nova.api.openstack.compute.servers.ServersController object at 0x6c05950>>, body: {"server":{"flavorRef":"1","name":"Martin-test","imageRef":"3b1196a4-cbc6-4b1c-b2bf-6e1c09b5b6f8","security_groups":[{"name":"e709cf24-f1b9-46f1-a4b9-25c74ac45a95"}],"networks":[{"uuid":"f8e79397-5691-4502-bd91-17517b3cae2f"}],"block_device_mapping_v2":[{"boot_index":0,"delete_on_termination":true,"destination_type":"local","source_type":"image","uuid":"3b1196a4-cbc6-4b1c-b2bf-6e1c09b5b6f8"}]}} _process_stack /usr/lib/python2.7/site-packages/nova/api/openstack/wsgi.py:609
2018-03-16 15:12:06.433 34 DEBUG nova.osapi_compute.wsgi.server [req-ddbb6656-f851-4533-a643-e23c6c942883 - - - - -] (34) accepted ('10.10.153.172', 49508) server /usr/lib/python2.7/site-packages/eventlet/wsgi.py:883
2018-03-16 15:12:06.465 35 DEBUG oslo_concurrency.lockutils [req-ef93825e-c5b7-4a35-953f-4fd78a449958 - - - - -] Lock "00000000-0000-0000-0000-000000000000" acquired by "nova.context.get_or_set_cached_cell_and_set_connections" :: waited 0.000s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:270
2018-03-16 15:12:06.467 35 DEBUG oslo_concurrency.lockutils [req-ef93825e-c5b7-4a35-953f-4fd78a449958 - - - - -] Lock "00000000-0000-0000-0000-000000000000" released by "nova.context.get_or_set_cached_cell_and_set_connections" :: held 0.002s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:282
2018-03-16 15:12:06.469 35 DEBUG oslo_concurrency.lockutils [req-ef93825e-c5b7-4a35-953f-4fd78a449958 - - - - -] Lock "755ddf46-90c4-4464-94fd-655f56b9f857" acquired by "nova.context.get_or_set_cached_cell_and_set_connections" :: waited 0.000s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:270
2018-03-16 15:12:06.471 35 DEBUG oslo_concurrency.lockutils [req-ef93825e-c5b7-4a35-953f-4fd78a449958 - - - - -] Lock "755ddf46-90c4-4464-94fd-655f56b9f857" released by "nova.context.get_or_set_cached_cell_and_set_connections" :: held 0.001s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:282
2018-03-16 15:12:06.472 34 DEBUG nova.api.openstack.wsgi [req-f4e60355-3898-44eb-a0a4-0f3631a643d0 32366f03b6db40a2a376493f281bcb42 924a712f3834478ab20af078b4214830 - default default] Calling method '<bound method ServersController.show of <nova.api.openstack.compute.servers.ServersController object at 0x6d57e10>>' _process_stack /usr/lib/python2.7/site-packages/nova/api/openstack/wsgi.py:612
2018-03-16 15:12:06.489 34 DEBUG nova.compute.api [req-f4e60355-3898-44eb-a0a4-0f3631a643d0 32366f03b6db40a2a376493f281bcb42 924a712f3834478ab20af078b4214830 - default default] [instance: 090e3ccd-28eb-42d8-8997-1758661c5d2a] Fetching instance by UUID get /usr/lib/python2.7/site-packages/nova/compute/api.py:2279
2018-03-16 15:12:06.660 34 DEBUG nova.policy [req-f4e60355-3898-44eb-a0a4-0f3631a643d0 32366f03b6db40a2a376493f281bcb42 924a712f3834478ab20af078b4214830 - default default] Policy check for os_compute_api:os-hide-server-addresses failed with credentials {'service_roles': [], 'user_id': u'32366f03b6db40a2a376493f281bcb42', 'roles': [u'heat_stack_owner', u'admin'], 'user_domain_id': u'default', 'service_project_id': None, 'service_user_id': None, 'service_user_domain_id': None, 'service_project_domain_id': None, 'is_admin_project': True, 'is_admin': True, 'project_id': u'924a712f3834478ab20af078b4214830', 'project_domain_id': u'default'} authorize /usr/lib/python2.7/site-packages/nova/policy.py:168
2018-03-16 15:12:06.917 35 DEBUG nova.network.neutronv2.api [req-ef93825e-c5b7-4a35-953f-4fd78a449958 - - - - -] validate_networks() for [(u'f8e79397-5691-4502-bd91-17517b3cae2f', None, None, None)] validate_networks /usr/lib/python2.7/site-packages/nova/network/neutronv2/api.py:1692
2018-03-16 15:12:07.041 34 INFO nova.osapi_compute.wsgi.server [req-f4e60355-3898-44eb-a0a4-0f3631a643d0 32366f03b6db40a2a376493f281bcb42 924a712f3834478ab20af078b4214830 - default default] 10.10.153.171,10.10.153.172 "GET /v2.1/924a712f3834478ab20af078b4214830/servers/090e3ccd-28eb-42d8-8997-1758661c5d2a HTTP/1.1" status: 200 len: 1791 time: 0.6052020
2018-03-16 15:12:07.063 34 DEBUG nova.api.openstack.wsgi [req-7224d73c-8585-4c7d-9c96-866a91648680 32366f03b6db40a2a376493f281bcb42 924a712f3834478ab20af078b4214830 - default default] Calling method '<bound method ServersController.show of <nova.api.openstack.compute.servers.ServersController object at 0x6d57e10>>' _process_stack /usr/lib/python2.7/site-packages/nova/api/openstack/wsgi.py:612
2018-03-16 15:12:07.082 34 DEBUG nova.compute.api [req-7224d73c-8585-4c7d-9c96-866a91648680 32366f03b6db40a2a376493f281bcb42 924a712f3834478ab20af078b4214830 - default default] [instance: 090e3ccd-28eb-42d8-8997-1758661c5d2a] Fetching instance by UUID get /usr/lib/python2.7/site-packages/nova/compute/api.py:2279
2018-03-16 15:12:07.200 34 DEBUG nova.policy [req-7224d73c-8585-4c7d-9c96-866a91648680 32366f03b6db40a2a376493f281bcb42 924a712f3834478ab20af078b4214830 - default default] Policy check for os_compute_api:os-hide-server-addresses failed with credentials {'service_roles': [], 'user_id': u'32366f03b6db40a2a376493f281bcb42', 'roles': [u'heat_stack_owner', u'admin'], 'user_domain_id': u'default', 'service_project_id': None, 'service_user_id': None, 'service_user_domain_id': None, 'service_project_domain_id': None, 'is_admin_project': True, 'is_admin': True, 'project_id': u'924a712f3834478ab20af078b4214830', 'project_domain_id': u'default'} authorize /usr/lib/python2.7/site-packages/nova/policy.py:168
2018-03-16 15:12:07.332 34 INFO nova.osapi_compute.wsgi.server [req-7224d73c-8585-4c7d-9c96-866a91648680 32366f03b6db40a2a376493f281bcb42 924a712f3834478ab20af078b4214830 - default default] 10.10.153.171,10.10.153.172 "GET /v2.1/924a712f3834478ab20af078b4214830/servers/090e3ccd-28eb-42d8-8997-1758661c5d2a HTTP/1.1" status: 200 len: 1791 time: 0.2861421
2018-03-16 15:12:07.466 35 DEBUG nova.virt.hardware [req-ef93825e-c5b7-4a35-953f-4fd78a449958 - - - - -] emulator threads policy constraint: None get_emulator_threads_constraint /usr/lib/python2.7/site-packages/nova/virt/hardware.py:1287
2018-03-16 15:12:07.478 35 DEBUG nova.quota [req-ef93825e-c5b7-4a35-953f-4fd78a449958 - - - - -] Getting quotas for project 924a712f3834478ab20af078b4214830. Resources: ['metadata_items'] _get_quotas /usr/lib/python2.7/site-packages/nova/quota.py:442
2018-03-16 15:12:07.486 35 DEBUG nova.quota [req-ef93825e-c5b7-4a35-953f-4fd78a449958 - - - - -] Getting quotas for user 32366f03b6db40a2a376493f281bcb42 and project 924a712f3834478ab20af078b4214830. Resources:['metadata_items'] _get_quotas /usr/lib/python2.7/site-packages/nova/quota.py:434
2018-03-16 15:12:07.514 35 DEBUG nova.quota [req-ef93825e-c5b7-4a35-953f-4fd78a449958 - - - - -] Getting quotas for project 924a712f3834478ab20af078b4214830. Resources: ['injected_files'] _get_quotas /usr/lib/python2.7/site-packages/nova/quota.py:442
2018-03-16 15:12:07.519 35 DEBUG nova.quota [req-ef93825e-c5b7-4a35-953f-4fd78a449958 - - - - -] Getting quotas for user 32366f03b6db40a2a376493f281bcb42 and project 924a712f3834478ab20af078b4214830. Resources:['injected_files'] _get_quotas /usr/lib/python2.7/site-packages/nova/quota.py:434
2018-03-16 15:12:07.561 35 DEBUG nova.quota [req-ef93825e-c5b7-4a35-953f-4fd78a449958 - - - - -] Getting quotas for project 924a712f3834478ab20af078b4214830. Resources: ['injected_file_content_bytes', 'injected_file_path_bytes'] _get_quotas /usr/lib/python2.7/site-packages/nova/quota.py:442
2018-03-16 15:12:07.567 35 DEBUG nova.quota [req-ef93825e-c5b7-4a35-953f-4fd78a449958 - - - - -] Getting quotas for user 32366f03b6db40a2a376493f281bcb42 and project 924a712f3834478ab20af078b4214830. Resources:['injected_file_content_bytes', 'injected_file_path_bytes'] _get_quotas /usr/lib/python2.7/site-packages/nova/quota.py:434
2018-03-16 15:12:07.585 35 DEBUG oslo_concurrency.lockutils [req-28626792-67c9-4a44-a446-57cf2fcd9ba8 32366f03b6db40a2a376493f281bcb42 924a712f3834478ab20af078b4214830 - default default] Lock "00000000-0000-0000-0000-000000000000" acquired by "nova.context.get_or_set_cached_cell_and_set_connections" :: waited 0.000s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:270
And I have 2 instances instead of 1:
root@k8os02:~# openstack server list
WARNING: Failed to import plugin orchestration.
+--------------------------------------+-------------+---------+---------------------------+--------+---------+
| ID | Name | Status | Networks | Image | Flavor |
+--------------------------------------+-------------+---------+---------------------------+--------+---------+
| ac2d144f-18d4-42a8-ac16-09da112a5735 | Martin-test | ACTIVE | demo-network=10.10.153.4 | coreOS | m1.tiny |
| 090e3ccd-28eb-42d8-8997-1758661c5d2a | Martin-test | ACTIVE | demo-network=10.10.153.7 | coreOS | m1.tiny |
| 7a0ae779-092f-4d63-bd33-0c4a2ec07f0f | miso | ACTIVE | demo-network=10.10.153.10 | cirros | m1.tiny |
| e37d8880-c0f5-4fa2-ade1-04d7dc0ffcef | miso | ACTIVE | demo-network=10.10.153.6 | cirros | m1.tiny |
| e979e475-4ea5-42e6-aad5-7bd4b08003ff | test-cirros | ERROR | | | m1.tiny |
+--------------------------------------+-------------+---------+---------------------------+--------+---------+
I hope that will be helpful
Hi Guys.
I am just admin of CFME and I was fased with the same issue on fine-3 and OS Newton. But the problem was in openstack nova-api pagination logic:
https://bugzilla.redhat.com/show_bug.cgi?id=1544713
But from my case I have duplicates only on CFME side but not on OS side.
What provision method did you use ? Service provision or vm provision ? Can you enable debug on appliances and search for number_of_vms option for miq_provision tasks ?
Hi,
we have really problem with duplication on OS side. As you can see in logs, number_of_vms is 1 and we are using vm_provision method:
[----] I, [2018-03-19T07:55:38.482486 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Flavor: [1]
[----] I, [2018-03-19T07:55:38.482722 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Guest A ccess Key Pair: []
[----] I, [2018-03-19T07:55:38.482964 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Securit y Group: [[]]
[----] I, [2018-03-19T07:55:38.483219 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Network : [[{"net_id"=>"f8e79397-5691-4502-bd91-17517b3cae2f"}]]
[----] I, [2018-03-19T07:55:38.483673 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Clone O ptions: [:name](String) = "michal-dupl"
[----] I, [2018-03-19T07:55:38.483962 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Clone O ptions: [:image_ref](String) = "099b564e-5571-49d2-aee7-f80878a2e315"
[----] I, [2018-03-19T07:55:38.484264 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Clone O ptions: [:flavor_ref](String) = "1"
[----] I, [2018-03-19T07:55:38.484676 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Clone O ptions: [:nics][0]["net_id"](String) = "f8e79397-5691-4502-bd91-17517b3cae2f"
[----] I, [2018-03-19T07:55:38.485075 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Clone O ptions: [:block_device_mapping_v2][0][:name](String) = "root"
[----] I, [2018-03-19T07:55:38.485386 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Clone O ptions: [:block_device_mapping_v2][0][:size](Fixnum) = 1
[----] I, [2018-03-19T07:55:38.485977 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Clone O ptions: [:block_device_mapping_v2][0][:source_type](String) = "image"
[----] I, [2018-03-19T07:55:38.486686 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Clone O ptions: [:block_device_mapping_v2][0][:destination_type](String) = "local"
[----] I, [2018-03-19T07:55:38.487658 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Clone O ptions: [:block_device_mapping_v2][0][:boot_index](Fixnum) = 0
[----] I, [2018-03-19T07:55:38.488222 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Clone O ptions: [:block_device_mapping_v2][0][:delete_on_termination](TrueClass) = true
[----] I, [2018-03-19T07:55:38.488712 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Clone O ptions: [:block_device_mapping_v2][0][:uuid](String) = "099b564e-5571-49d2-aee7-f80878a2e315"
[----] I, [2018-03-19T07:55:38.533998 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Prov Op tions: [:initial_pass](TrueClass) = true
[----] I, [2018-03-19T07:55:38.534685 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Prov Op tions: [:src_vm_id][0](Fixnum) = 6
[----] I, [2018-03-19T07:55:38.535076 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Prov Op tions: [:src_vm_id][1](String) = "cirros"
[----] I, [2018-03-19T07:55:38.535642 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Prov Op tions: [:miq_request_dialog_name](String) = "miq_provision_openstack_dialogs_template"
[----] I, [2018-03-19T07:55:38.536348 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Prov Op tions: [:customize_enabled][0](String) = "enabled"
[----] I, [2018-03-19T07:55:38.536947 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Prov Op tions: [:current_tab_key](Symbol) = :schedule
[----] I, [2018-03-19T07:55:38.537405 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Prov Options: [:owner_phone](NilClass) = nil
[----] I, [2018-03-19T07:55:38.537706 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Prov Options: [:owner_country](NilClass) = nil
[----] I, [2018-03-19T07:55:38.538001 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Prov Options: [:owner_phone_mobile](NilClass) = nil
[----] I, [2018-03-19T07:55:38.538448 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Prov Options: [:owner_title](NilClass) = nil
[----] I, [2018-03-19T07:55:38.538754 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Prov Options: [:owner_first_name](NilClass) = nil
[----] I, [2018-03-19T07:55:38.539113 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Prov Options: [:owner_manager](NilClass) = nil
[----] I, [2018-03-19T07:55:38.539411 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Prov Options: [:owner_address](NilClass) = nil
[----] I, [2018-03-19T07:55:38.539701 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Prov Options: [:owner_company](NilClass) = nil
[----] I, [2018-03-19T07:55:38.540011 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Prov Options: [:owner_last_name](NilClass) = nil
[----] I, [2018-03-19T07:55:38.540412 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Prov Options: [:owner_manager_mail](NilClass) = nil
[----] I, [2018-03-19T07:55:38.540840 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Prov Options: [:owner_city](NilClass) = nil
[----] I, [2018-03-19T07:55:38.541767 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Prov Options: [:owner_department](NilClass) = nil
[----] I, [2018-03-19T07:55:38.542251 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Prov Options: [:owner_load_ldap](NilClass) = nil
[----] I, [2018-03-19T07:55:38.542560 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Prov Options: [:owner_manager_phone](NilClass) = nil
[----] I, [2018-03-19T07:55:38.542855 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Prov Options: [:owner_state](NilClass) = nil
[----] I, [2018-03-19T07:55:38.543150 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Prov Options: [:owner_office](NilClass) = nil
[----] I, [2018-03-19T07:55:38.543443 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Prov Options: [:owner_zip](NilClass) = nil
[----] I, [2018-03-19T07:55:38.543730 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Prov Options: [:owner_email](String) = "miso@aa.cz"
[----] I, [2018-03-19T07:55:38.544213 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Prov Options: [:request_notes](NilClass) = nil
[----] I, [2018-03-19T07:55:38.545026 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Prov Options: [:placement_auto][0](TrueClass) = true
[----] I, [2018-03-19T07:55:38.545696 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Prov Options: [:placement_auto][1](Fixnum) = 1
[----] I, [2018-03-19T07:55:38.546504 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Prov Options: [:placement_availability_zone][0](NilClass) = nil
[----] I, [2018-03-19T07:55:38.547105 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Prov Options: [:placement_availability_zone][1](NilClass) = nil
[----] I, [2018-03-19T07:55:38.547774 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Prov Options: [:cloud_tenant][0](NilClass) = nil
[----] I, [2018-03-19T07:55:38.548365 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Prov Options: [:cloud_tenant][1](NilClass) = nil
[----] I, [2018-03-19T07:55:38.548879 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Prov Options: [:cloud_network][0](Fixnum) = 3
[----] I, [2018-03-19T07:55:38.549331 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Prov Options: [:cloud_network][1](String) = "demo-network"
[----] I, [2018-03-19T07:55:38.549825 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Prov Options: [:security_groups][0](NilClass) = nil
[----] I, [2018-03-19T07:55:38.550215 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Prov Options: [:security_groups][1](NilClass) = nil
[----] I, [2018-03-19T07:55:38.550733 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Prov Options: [:floating_ip_address][0](NilClass) = nil
[----] I, [2018-03-19T07:55:38.551176 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Prov Options: [:floating_ip_address][1](NilClass) = nil
[----] I, [2018-03-19T07:55:38.551547 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Prov Options: [:number_of_vms][0](Fixnum) = 1
[----] I, [2018-03-19T07:55:38.551850 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Prov Options: [:number_of_vms][1](String) = "1"
[----] I, [2018-03-19T07:55:38.552146 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Prov Options: [:vm_description](NilClass) = nil
[----] I, [2018-03-19T07:55:38.552614 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Prov Options: [:vm_prefix](NilClass) = nil
[----] I, [2018-03-19T07:55:38.552954 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Prov Options: [:vm_name](String) = "michal-dupl"
[----] I, [2018-03-19T07:55:38.553632 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Prov Options: [:schedule_type][0](String) = "immediately"
[----] I, [2018-03-19T07:55:38.554648 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Prov Options: [:schedule_type][1](String) = "Immediately on Approval"
[----] I, [2018-03-19T07:55:38.555140 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Prov Options: [:schedule_time](ActiveSupport::TimeWithZone) = Tue, 20 Mar 2018 00:00:00 UTC +00:00
[----] I, [2018-03-19T07:55:38.555621 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Prov Options: [:retirement][0](Fixnum) = 0
[----] I, [2018-03-19T07:55:38.555923 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Prov Options: [:retirement][1](String) = "Indefinite"
[----] I, [2018-03-19T07:55:38.556309 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Prov Options: [:retirement_warn][0](Fixnum) = 604800
[----] I, [2018-03-19T07:55:38.556797 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Prov Options: [:retirement_warn][1](String) = "1 Week"
[----] I, [2018-03-19T07:55:38.557271 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Prov Options: [:instance_type][0](Fixnum) = 1
[----] I, [2018-03-19T07:55:38.557576 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Prov Options: [:instance_type][1](String) = "m1.tiny: 1 CPUs, 512 MB RAM, 1 GB Root Disk"
[----] I, [2018-03-19T07:55:38.557930 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Prov Options: [:guest_access_key_pair][0](Fixnum) = 0
[----] I, [2018-03-19T07:55:38.558280 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Prov Options: [:guest_access_key_pair][1](NilClass) = nil
[----] I, [2018-03-19T07:55:38.558757 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Prov Options: [:name](NilClass) = nil
[----] I, [2018-03-19T07:55:38.559254 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Prov Options: [:size](NilClass) = nil
[----] I, [2018-03-19T07:55:38.559722 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Prov Options: [:delete_on_terminate](FalseClass) = false
[----] I, [2018-03-19T07:55:38.560148 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Prov Options: [:customization_template_script](NilClass) = nil
[----] I, [2018-03-19T07:55:38.560608 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Prov Options: [:dns_servers](NilClass) = nil
[----] I, [2018-03-19T07:55:38.561123 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Prov Options: [:dns_suffixes](NilClass) = nil
[----] I, [2018-03-19T07:55:38.561695 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Prov Options: [:addr_mode][0](String) = "dhcp"
[----] I, [2018-03-19T07:55:38.562253 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Prov Options: [:addr_mode][1](String) = "DHCP"
[----] I, [2018-03-19T07:55:38.562698 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Prov Options: [:linux_host_name](NilClass) = nil
[----] I, [2018-03-19T07:55:38.563083 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Prov Options: [:gateway](NilClass) = nil
[----] I, [2018-03-19T07:55:38.563732 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Prov Options: [:linux_domain_name](NilClass) = nil
[----] I, [2018-03-19T07:55:38.564071 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Prov Options: [:subnet_mask](NilClass) = nil
[----] I, [2018-03-19T07:55:38.564489 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Prov Options: [:customization_template_id][0](NilClass) = nil
[----] I, [2018-03-19T07:55:38.564790 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Prov Options: [:customization_template_id][1](NilClass) = nil
[----] I, [2018-03-19T07:55:38.565087 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Prov Options: [:root_password](NilClass) = "<PROTECTED>"
[----] I, [2018-03-19T07:55:38.565412 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Prov Options: [:hostname](NilClass) = nil
[----] I, [2018-03-19T07:55:38.565773 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Prov Options: [:start_date](String) = "3/20/2018"
[----] I, [2018-03-19T07:55:38.566083 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Prov Options: [:start_hour](String) = "00"
[----] I, [2018-03-19T07:55:38.566458 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Prov Options: [:start_min](String) = "00"
[----] I, [2018-03-19T07:55:38.567146 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Prov Options: [:src_ems_id][0](Fixnum) = 4
[----] I, [2018-03-19T07:55:38.567450 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Prov Options: [:src_ems_id][1](String) = "OpenStack on 10.10.153.172"
[----] I, [2018-03-19T07:55:38.567792 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Prov Options: [:requester_group](String) = "EvmGroup-super_administrator"
[----] I, [2018-03-19T07:55:38.568217 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Prov Options: [:owner_group](NilClass) = nil
[----] I, [2018-03-19T07:55:38.568555 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Prov Options: [:delivered_on](Time) = 2018-03-19 07:54:59 UTC
[----] I, [2018-03-19T07:55:38.568844 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Prov Options: [:pass](Fixnum) = 1
[----] I, [2018-03-19T07:55:38.569191 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Prov Options: [:dns_domain](NilClass) = nil
[----] I, [2018-03-19T07:55:38.569529 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Prov Options: [:vm_target_name](String) = "michal-dupl"
[----] I, [2018-03-19T07:55:38.569818 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Prov Options: [:vm_target_hostname](String) = "michal-dupl"
[----] I, [2018-03-19T07:55:38.570212 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Prov Options: [:dest_availability_zone][0](NilClass) = nil
[----] I, [2018-03-19T07:55:38.570689 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Prov Options: [:dest_availability_zone][1](NilClass) = nil
[----] I, [2018-03-19T07:55:38.571317 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#log_clone_options) Prov Options: [:networks][0]["net_id"](String) = "f8e79397-5691-4502-bd91-17517b3cae2f"
[----] I, [2018-03-19T07:55:38.572054 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager#with_provider_connection) Connecting through ManageIQ::Providers::Openstack::CloudManager: [OpenStack on 10.10.153.172]
[----] I, [2018-03-19T07:55:39.628552 #7:cc7130] INFO -- : MIQ(MiqServer#monitor_loop) Server Monitoring Complete - Timings: {:server_dequeue=>0.016034603118896484, :worker_monitor=>1.9352881908416748, :worker_dequeue=>0.014008283615112305, :total_time=>1.9660146236419678}
[----] I, [2018-03-19T07:55:41.210063 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) Starting Phase <poll_clone_complete>
[----] I, [2018-03-19T07:55:41.233253 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager#with_provider_connection) Connecting through ManageIQ::Providers::Openstack::CloudManager: [OpenStack on 10.10.153.172]
[----] I, [2018-03-19T07:55:41.774065 #10491:cc7130] INFO -- : Q-task_id([miq_provision_6]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Provision#poll_clone_complete) Clone of [cirros] to Vm [michal-dupl] is build
On the other hand, there are 2 create API calls:
2018-03-19 08:55:38.964 35 DEBUG nova.api.openstack.wsgi [req-f9ffaa4f-9395-4cc5-9df5-ecbfe4bf78bb 32366f03b6db40a2a376493f281bcb42924a712f3834478ab20af078b4214830 - default default] Action: 'create', calling method: <bound method ServersController.create of <nova.api.openstack.compute.servers.ServersController object at 0x6c05950>>, body: {"server":{"flavorRef":"1","name":"michal-dupl","imageRef":"099b564e-5571-49d2-aee7-f80878a2e315","security_groups":[],"networks":[{"uuid":"f8e79397-5691-4502-bd91-17517b3cae2f"}],"block_device_mapping_v2":[{"boot_index":0,"delete_on_termination":true,"destination_type":"local","source_type":"image","uuid":"099b564e-5571-49d2-aee7-f80878a2e315"}]}} _process_stack /usr/lib/python2.7/site-packages/nova/api/openstack/wsgi.py:609
2018-03-19 08:55:41.231 35 DEBUG nova.api.openstack.wsgi [req-560c6266-8551-4dd0-9929-f605be464680 32366f03b6db40a2a376493f281bcb42 924a712f3834478ab20af078b4214830 - default default] Action: 'create', calling method: <bound method ServersController.create of <nova.api.openstack.compute.servers.ServersController object at 0x6c05950>>, body: {"server":{"flavorRef":"1","name":"michal-dupl","imageRef":"099b564e-5571-49d2-aee7-f80878a2e315","security_groups":[],"networks":[{"uuid":"f8e79397-5691-4502-bd91-17517b3cae2f"}],"block_device_mapping_v2":[{"boot_index":0,"delete_on_termination":true,"destination_type":"local","source_type":"image","uuid":"099b564e-5571-49d2-aee7-f80878a2e315"}]}} _process_stack /usr/lib/python2.7/site-packages/nova/api/openstack/wsgi.py:609
When I create vm instance from the Horizon dashboard, it creates only one instance and there is only one create call in nova-api.log
2018-03-19 13:50:01.229 34 DEBUG nova.api.openstack.wsgi [req-d5b319ba-fe4e-4ddc-a9a3-8264f0c7cf7b 32366f03b6db40a2a376493f281bcb42 924a712f3834478ab20af078b4214830 - default default] Action: 'create', calling method: <bound method ServersController.create of <nova.api.openstack.compute.servers.ServersController object at 0x6958150>>, body: {"server": {"name": "duplicate-test", "imageRef": "", "availability_zone": "nova", "key_name": "mykey", "flavorRef": "1", "OS-DCF:diskConfig": "AUTO", "max_count": 1, "block_device_mapping_v2": [{"boot_index": "0", "uuid": "099b564e-5571-49d2-aee7-f80878a2e315", "volume_size": 1, "device_name": "vda", "source_type": "image", "destination_type": "volume", "delete_on_termination": false}], "min_count": 1, "networks": [{"uuid": "f8e79397-5691-4502-bd91-17517b3cae2f"}], "security_groups": [{"name": "e709cf24-f1b9-46f1-a4b9-25c74ac45a95"}]}} _process_stack /usr/lib/python2.7/site-packages/nova/api/openstack/wsgi.py:609So the issue exists only when running ManageIQ from docker image. OpenStack OVA and Vagrant image are running correctly and no duplicated instances are created.