Tina - Please work with Billy to recreate this issue.
Hi Josh, The reason for the error appears to be an invalid user, user_name=qo386420 passed as an argument to the create_provision_request method. The automation.log error is very misleading. The evm.log shows the real error: MIQ(MiqProvisionVirtWorkflow.from_ws_ver_1_x) <Couldn't find User with [WHERE "users"."region" = ? AND "users"."userid" = ?]> The create_provision_request method should have reported the invalid user. While we're working on a fix to the method, could you ask the customer to check if the user: qo386420 is valid? Thanks, Tina evm.log..... [----] I, [2016-01-12T10:15:55.209285 #2993:58e8014] INFO -- : Q-task_id([service_template_provision_task_1000000000052]) <AutomationEngine> <AEMethod vmware_build_vmprovision_request> Build: 1 - Building provision request with the following arguments: ["1.1", "name=CF-Centos6-stdfs|guid=c6a93884-a8ca-11e5-b617-005056834234", "vm_name=tttttt|number_of_vms=1|provision_type=vmware|cores_per_socket=1|vm_memory=512|retirement=172800|retirement_warn=86400", "user_name=qo386420|owner_first_name=Rich|owner_last_name=Caldwell|owner_email=Rich.Caldwell", "environment=test|role=app|flex_monitor=false|flavor=xsmall", "service_name=Test_as_Admin_User|dialog_service_name=Test_as_Admin_User|service_description=logged in as caldwell|dialog_service_description=logged in as caldwell|template=c6a93884-a8ca-11e5-b617-005056834234|flavor=xsmall|add_disk1=10|group_id=1000000000023|group_name=IT-RND-|service_id=1000000000016|service_guid=bcdb8446-b947-11e5-be76-005056831180|environment=test|role=app|flex_monitor=false", nil, nil] [----] W, [2016-01-12T10:15:55.211550 #2993:58e8014] WARN -- : Q-task_id([service_template_provision_task_1000000000052]) MIQ(MiqProvisionVirtWorkflow.from_ws_ver_1_x) Web-service provisioning starting with interface version <1.1> by requester <admin> [----] E, [2016-01-12T10:15:55.212923 #2993:58e8014] ERROR -- : Q-task_id([service_template_provision_task_1000000000052]) MIQ(MiqProvisionVirtWorkflow.from_ws_ver_1_x) <Couldn't find User with [WHERE "users"."region" = ? AND "users"."userid" = ?]> [----] E, [2016-01-12T10:15:55.214517 #2993:926a418] ERROR -- : Q-task_id([service_template_provision_task_1000000000052]) <AutomationEngine> <AEMethod vmware_build_vmprovision_request> [ActiveRecord] /opt/rh/rh-ruby22/root/usr/share/ruby/drb/drb.rb:1149:in `method_missing’ <code: request = $evm.execute('create_provision_request', *args)>:384:in `build_provision_request’
Your logs indicate that the user_name sent to provisioning is 'qo386420' for both test99 and test100 service provision requests as shown below(look for user_name): [----] I, [2016-01-18T08:53:46.752891 #16652:177b428] INFO -- : Q-task_id([service_template_provision_task_1000000000145]) <AutomationEngine> <AEMethod vmware_build_vmprovision_request> Build: 1 - Building provision request with the following arguments: ["1.1", "name=CF-Centos6-stdfs|guid=c6a93884-a8ca-11e5-b617-005056834234", "number_of_vms=1|provision_type=vmware|vm_name=changeme|vlan=VM Network|cores_per_socket=1|vm_memory=4096|retirement=7776000|retirement_warn=604800", "user_name=qo386420|owner_first_name=Rich|owner_last_name=Caldwell|owner_email=Rich.Caldwell", "environment=prod|role=app|flavor=medium", "service_name=test99|dialog_service_name=test99|service_description=test99|dialog_service_description=test99|network=ent-dhcp|dialog_network=ent-dhcp|template=c6a93884-a8ca-11e5-b617-005056834234|flavor=medium|group_id=1000000000023|group_name=IT-RND-|service_id=1000000000045|service_guid=40641a3a-bdf3-11e5-b04e-005056834234|environment=prod|role=app", nil, nil] ----] I, [2016-01-18T09:01:08.363580 #16649:5dd5cac] INFO -- : Q-task_id([service_template_provision_task_1000000000148]) <AutomationEngine> <AEMethod vmware_build_vmprovision_request> Build: 1 - Building provision request with the following arguments: ["1.1", "name=CF-Centos6-stdfs|guid=c6a93884-a8ca-11e5-b617-005056834234", "number_of_vms=1|provision_type=vmware|vm_name=changeme|vlan=VM Network|cores_per_socket=1|vm_memory=4096|retirement=7776000|retirement_warn=604800", "user_name=qo386420|owner_first_name=Rich|owner_last_name=Caldwell|owner_email=Rich.Caldwell", "environment=prod|role=app|flavor=medium", "service_name=test100|dialog_service_name=test100|service_description=test100|dialog_service_description=test100|network=ent-dhcp|dialog_network=ent-dhcp|template=c6a93884-a8ca-11e5-b617-005056834234|flavor=medium|group_id=1000000000023|group_name=IT-RND-|service_id=1000000000046|service_guid=453c9dce-bdf4-11e5-b04e-005056834234|environment=prod|role=app", nil, nil] Could you do the following in a test environment: Using the Automate Explorer: 1. Navigate to the /CloudformsPOC/Service/Provisioning/Statemachines/Methods class 2. Edit the vmware_build_provision_request method. Note - We need to make a very simple change to the get_requester method code. I've listed my code since I'm not sure if your method differs. My line 138 reads: matching_options_hash[:user_name] = /^[^@]*/.match(@user.userid).to_s We need to make a copy of that line, and comment it out. Then modify the copied line to read: matching_options_hash[:user_name] = @user.userid The changed code should look like this: #matching_options_hash[:user_name] = /^[^@]*/.match(@user.userid).to_s matching_options_hash[:user_name] = @user.userid 3. Save the method. 4. Provision Service. my copy of get_requester code inside vmware_build_provision_request automate method for reference: # get requester and tenant information and allow a userid for provisioning on behalf of def get_requester(build, matching_options_hash, matching_tags_hash) log(:info, "Processing get_requester...", true) @user = $evm.vmdb('user').find_by_id(matching_options_hash[:evm_owner_id]) || $evm.vmdb('user').find_by_userid(matching_options_hash[:userid]) @user ||= $evm.vmdb('user').find_by_id($evm.root['user_id']) matching_options_hash[:user_name] = /^[^@]*/.match(@user.userid).to_s matching_options_hash[:owner_first_name] = @user.first_name ? @user.first_name : 'Cloud' matching_options_hash[:owner_last_name] = @user.last_name ? @user.last_name : 'Admin' matching_options_hash[:owner_email] = @user.email ? @user.email : $evm.object['to_email_address'] log(:info, "Build: #{build} - User: #{@user.userid} id: #{@user.id} email: #{@user.email}") # Stuff the current group information matching_options_hash[:group_id] = @user.current_group.id matching_options_hash[:group_name] = @user.current_group.description log(:info, "Build: #{build} - Group: #{@user.current_group.description} id: #{@user.current_group.id}") log(:info, "Processing get_requester...Complete", true) end Thanks, Tina
One additional request: Could you navigate to Configure/Configuration/Access Control/Users and provide a screen shot of the user in question. Thanks, Tina
My code is slightly different than yours, but I have made the requisite changes and that resolves this issue. I successfully provisioned a service using both short (qo386420) and long name login (qo386420.com). However, regardless of how or who I log in as, when I provision this service I ask for 1 VM, but I get two VMs created with different naming conventions. For example, I told the name to be "testlongname". I got 2 VMs created in this service named "testlongname" and "test_0043". "testlongname" has correct number of CPUs and Memory, "test_0043" has wrong number of both. Not sure why the test_0043 VM is being created. def get_requester(build, merged_options_hash, merged_tags_hash) ##Line 136 in my code starts here log_and_update_message(:info, "Processing get_requester...", true) @user = $evm.vmdb('user').find_by_id(merged_options_hash[:evm_owner_id]) || $evm.vmdb('user').find_by_userid(merged_options_hash[:userid]) || $evm.root['user'] ###merged_options_hash[:user_name] = /^[^@]*/.match(@user.userid).to_s merged_options_hash[:user_name] = @user.userid merged_options_hash[:owner_first_name] = @user.first_name ? @user.first_name : 'Cloud' merged_options_hash[:owner_last_name] = @user.last_name ? @user.last_name : 'Admin' merged_options_hash[:owner_email] = @user.email ? @user.email : $evm.object['to_email_address'] log_and_update_message(:info, "Build: #{build} - User: #{@user.userid} id: #{@user.id} email: #{@user.email}") # Stuff the current group information merged_options_hash[:group_id] = @user.current_group.id merged_options_hash[:group_name] = @user.current_group.description log_and_update_message(:info, "Build: #{build} - Group: #{merged_options_hash[:group_name]} " \ "id: #{merged_options_hash[:group_id]}") log_and_update_message(:info, "Processing get_requester...Complete", true) end ### Line 154 is this line
Created attachment 1116026 [details] Screen shot service with 2 VMs when one was requested
Created attachment 1116027 [details] User Account from LDAP creating service request This is the user account that I was logged in as when the service was failing. It's an Active Directory user account.
It appears as though there are multiple things going on here. 1. An invalid user causes create_provision_request automate call to break and log the following error: [----] E, [2016-01-12T10:15:55.212923 #2993:58e8014] ERROR -- : Q-task_id([service_template_provision_task_1000000000052]) MIQ(MiqProvisionVirtWorkflow.from_ws_ver_1_x) <Couldn't find User with [WHERE "users"."region" = ? AND "users"."userid" = ?]> We will make a fix for this. 2. The /CloudformsPOC/Service/Provisioning/Statemachines/Methods/vmware_build_provision_request method needed the following change to pass the correct userid: ###merged_options_hash[:user_name] = /^[^@]*/.match(@user.userid).to_s merged_options_hash[:user_name] = @user.userid 3. Two VMs are being provisioned from a service where only a single VM is expected. Waiting for additional information on the service anatomy, a screen shot showing the service and its resources.
Rich sent me the service screen shots last night and I'll look at the logs. Can we open a separate ticket for this issue?