[
https://issues.apache.org/jira/browse/CLOUDSTACK-2397?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13706400#comment-13706400
]
Sangeetha Hariharan commented on CLOUDSTACK-2397:
-------------------------------------------------
Advanced zone with Xen 6.1 hosts.
Deploy a Vm in this network by passing userdata.
Vm deployment errors out.
Following error seen in management-server.logs
2013-07-11 15:53:03,838 DEBUG
[network.router.VirtualNetworkApplianceManagerImpl] (Job-Executor-63:job-200)
Applying userdata and password entry in network Ntwk[2
05|Guest|8]
2013-07-11 15:53:03,852 DEBUG [agent.transport.Request]
(Job-Executor-63:job-200) Seq 1-1847328924: Sending { Cmd , MgmtId:
7200344900649, via: 1, Ver: v1, Flags
: 100011,
[{"com.cloud.agent.api.routing.SavePasswordCommand":{"password":"fnirq_cnffjbeq","vmIpAddress":"10.1.1.159","vmName":"san-1","executeInSequence":false,"
accessDetails":{"router.guest.ip":"10.1.1.1","zone.network.type":"Advanced","router.ip":"169.254.2.47","router.name":"r-65-VM"},"wait":0}},{"com.cloud.agent.api.r
outing.VmDataCommand":{"vmIpAddress":"10.1.1.159","vmName":"san-1","executeInSequence":false,"accessDetails":{"router.guest.ip":"10.1.1.1","zone.network.type":"Ad
vanced","router.ip":"169.254.2.47","router.name":"r-65-VM"},"wait":0}}] }
2013-07-11 15:53:03,852 DEBUG [agent.transport.Request]
(Job-Executor-63:job-200) Seq 1-1847328924: Executing: { Cmd , MgmtId:
7200344900649, via: 1, Ver: v1, Fl
ags: 100011,
[{"com.cloud.agent.api.routing.SavePasswordCommand":{"password":"fnirq_cnffjbeq","vmIpAddress":"10.1.1.159","vmName":"san-1","executeInSequence":fals
e,"accessDetails":{"router.guest.ip":"10.1.1.1","zone.network.type":"Advanced","router.ip":"169.254.2.47","router.name":"r-65-VM"},"wait":0}},{"com.cloud.agent.ap
i.routing.VmDataCommand":{"vmIpAddress":"10.1.1.159","vmName":"san-1","executeInSequence":false,"accessDetails":{"router.guest.ip":"10.1.1.1","zone.network.type":
"Advanced","router.ip":"169.254.2.47","router.name":"r-65-VM"},"wait":0}}] }
2013-07-11 15:53:03,852 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-93:null) Seq 1-1847328924: Executing request
2013-07-11 15:53:14,163 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-93:null) Seq 1-1847328924: Response Received:
2013-07-11 15:53:14,163 DEBUG [agent.transport.Request] (DirectAgent-93:null)
Seq 1-1847328924: Processing: { Ans: , MgmtId: 7200344900649, via: 1, Ver: v1,
Flags: 10,
[{"com.cloud.agent.api.Answer":{"result":true,"wait":0}},{"com.cloud.agent.api.Answer":{"result":false,"details":"vm_data
failed","wait":0}}] }
2013-07-11 15:53:14,163 DEBUG [agent.transport.Request]
(Job-Executor-63:job-200) Seq 1-1847328924: Received: { Ans: , MgmtId:
7200344900649, via: 1, Ver: v1, Flags: 10, { Answer, Answer } }
2013-07-11 15:53:14,163 INFO [cloud.vm.VirtualMachineManagerImpl]
(Job-Executor-63:job-200) Unable to contact resource.
com.cloud.exception.ResourceUnavailableException: Resource [DataCenter:1] is
unreachable: Unable to apply userdata and password entry on router
at
com.cloud.network.router.VirtualNetworkApplianceManagerImpl.applyRules(VirtualNetworkApplianceManagerImpl.java:3784)
at
com.cloud.network.router.VirtualNetworkApplianceManagerImpl.applyUserData(VirtualNetworkApplianceManagerImpl.java:2977)
at
com.cloud.network.element.VirtualRouterElement.addPasswordAndUserdata(VirtualRouterElement.java:944)
at
com.cloud.network.NetworkManagerImpl.prepareElement(NetworkManagerImpl.java:2006)
at
com.cloud.network.NetworkManagerImpl.prepareNic(NetworkManagerImpl.java:2112)
at
com.cloud.network.NetworkManagerImpl.prepare(NetworkManagerImpl.java:2053)
at
com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:849)
at
com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:557)
at
org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.deployVirtualMachine(VMEntityManagerImpl.java:243)
at
org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.deploy(VirtualMachineEntityImpl.java:209)
at
com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3317)
at
com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2877)
at
com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2863)
at
com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
at
org.apache.cloudstack.api.command.user.vm.DeployVMCmd.execute(DeployVMCmd.java:420)
at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:155)
at
com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:513)
at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
at java.util.concurrent.FutureTask.run(FutureTask.java:166)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
at java.lang.Thread.run(Thread.java:679)
Following error seen in SMlog
[18756] 2013-07-11 15:53:24.181558 #### VMOPS exit get_rule_logs_for_vms
####
[18600] 2013-07-11 15:53:24.472683 pread SUCCESS
[18600] 2013-07-11 15:53:24.473117 ['/bin/bash',
'/opt/xensource/bin/vm_data.sh', '-r', '169.254.2.47', '-v', '10.1.1.159',
'-F', 'metadata', '-f', 'local-ipv4', '-d', '/tmp/tmpoI9d28']
[18600] 2013-07-11 15:53:25.509686 pread SUCCESS
[18600] 2013-07-11 15:53:25.510143 ['/bin/bash',
'/opt/xensource/bin/vm_data.sh', '-r', '169.254.2.47', '-v', '10.1.1.159',
'-F', 'metadata', '-f', 'vm-id', '-d', '/tmp/tmpJ-9jXY']
[18600] 2013-07-11 15:53:26.550048 pread SUCCESS
[18600] 2013-07-11 15:53:26.550541 vmdata failed to write tempfile
[18600] 2013-07-11 15:53:26.550642 #### VMOPS exit vm_data ####
[18803] 2013-07-11 15:53:27.139606 #### VMOPS enter saveDhcpEntry ####
[18803] 2013-07-11 15:53:27.139726 ['/bin/bash',
'/opt/xensource/bin/dhcp_entry.sh', '-r', '169.254.2.47', '-v', '10.1.1.159',
'-m', '02:00:2a:38:00:21', '-n', 'san-1', '-d', '10.1.1.1', '-N', '10.1.1.1']
[18803] 2013-07-11 15:53:27.405636 pread SUCCESS
[18803] 2013-07-11 15:53:27.405818 #### VMOPS exit saveDhcpEntry ####
[18828] 2013-07-11 15:53:27.726588 #### VMOPS enter savePassword ####
[18828] 2013-07-11 15:53:27.726700 ['/bin/bash',
'/opt/xensource/bin/save_password_to_domr.sh', '-r', '169.254.2.47', '-v',
'10.1.1.159', '-p', 'fnirq_cnffjbeq', 'san-1']
[18828] 2013-07-11 15:53:27.999175 pread SUCCESS
[18828] 2013-07-11 15:53:27.999323 #### VMOPS exit savePassword ####
[18840] 2013-07-11 15:53:28.242552 #### VMOPS enter vm_data ####
[18840] 2013-07-11 15:53:28.242659 adding vmdata for VM with IP:
10.1.1.159 to router with IP: 169.254.2.47
[18840] 2013-07-11 15:53:28.243165 ['/bin/bash',
'/opt/xensource/bin/vm_data.sh', '-r', '169.254.2.47', '-v', '10.1.1.159',
'-F', 'metadata', '-f', 'public-hostname', '-d', '/tmp/tmp2wsfXj']
[18840] 2013-07-11 15:53:29.314518 pread SUCCESS
[18840] 2013-07-11 15:53:29.314965 ['/bin/bash',
'/opt/xensource/bin/vm_data.sh', '-r', '169.254.2.47', '-v', '10.1.1.159',
'-F', 'metadata', '-f', 'availability-zone', '-d', '/tmp/tmpwwcShV']
[18840] 2013-07-11 15:53:30.357707 pread SUCCESS
[18840] 2013-07-11 15:53:30.358151 ['/bin/bash',
'/opt/xensource/bin/vm_data.sh', '-r', '169.254.2.47', '-v', '10.1.1.159',
'-F', 'metadata', '-f', 'public-ipv4', '-d', '/tmp/tmpd8qqKo']
> Not able to deploy a Vm with userdata in Shared network/Isolated Network.
> -------------------------------------------------------------------------
>
> Key: CLOUDSTACK-2397
> URL: https://issues.apache.org/jira/browse/CLOUDSTACK-2397
> Project: CloudStack
> Issue Type: Bug
> Security Level: Public(Anyone can view this level - this is the
> default.)
> Components: Management Server
> Affects Versions: 4.2.0
> Environment: Build from pvlan
> Reporter: Sangeetha Hariharan
> Assignee: Venkata Siva Vijayendra Bhamidipati
> Priority: Critical
> Fix For: 4.2.0
>
> Attachments: logs.rar
>
>
> Steps to reproduce the problem:
> Advanced zone with Xen 6.1 hosts.
> Create a Shared network by passing private Vlan.
> Deploy a Vm in this network by passing userdata.
> Vm deployment errors out.
> GET
> command=deployVirtualMachine&zoneId=b5b71f7b-19a4-4f32-9512-d9b0eac382f3&templateId=b79f666e-b760-11e2-a38a-06f4b000042b&hypervisor=XenServer&serviceOfferingId=4480e764-0d39-4950-86a9-a422e7ae3b7d&networkIds=a2fb9fda-f6a1-4348-beb1-4e29367b3dbd&displayname=yo-userdata&name=yo-userdata&response=json&sessionkey=LqAvWj%2BQ0xeg3eqoKXMhOoA%2B53E%3D&userdata=Y2F0Y2ggbWUgaWYgeW91IGNhbg==
> 200 { "deployvirtualmachineresponse" :
> {"id":"05f1426d-6650-470f-8f6e-36b18b3bcd8c","jobid":"e3bd77a2-aca2-4c39-b85f-9f928c7af000"}
> }
> Following exception seen in management server log:
> 2013-05-08 13:47:27,815 DEBUG [agent.transport.Request]
> (Job-Executor-18:job-39) Seq 1-1674709490: Executing: { Cmd , MgmtId:
> 7647994577963, via: 1, Ver: v1, Flags: 100111,
> [{"routing.SavePasswordCommand":{"password":"fnirq_cnffjbeq","vmIpAddress":"10.223.161.116","vmName":"yo-userdata","accessDetails":{"router.guest.ip":"10.223.161.110","zone.network.type":"Advanced","router.ip":"169.254.0.235","router.name":"r-13-VM"},"wait":0}},{"routing.VmDataCommand":{"vmIpAddress":"10.223.161.116","vmName":"yo-userdata","accessDetails":{"router.guest.ip":"10.223.161.110","zone.network.type":"Advanced","router.ip":"169.254.0.235","router.name":"r-13-VM"},"wait":0}}]
> }
> 2013-05-08 13:47:27,815 DEBUG [agent.manager.DirectAgentAttache]
> (DirectAgent-164:null) Seq 1-1674709490: Executing request
> 2013-05-08 13:47:29,899 DEBUG [storage.secondary.SecondaryStorageManagerImpl]
> (secstorage-1:null) Zone 1 is ready to launch secondary storage VM
> 2013-05-08 13:47:30,039 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl]
> (consoleproxy-1:null) Zone 1 is ready to launch console proxy
> 2013-05-08 13:47:33,199 DEBUG
> [network.router.VirtualNetworkApplianceManagerImpl]
> (RouterStatusMonitor-1:null) Found 0 routers to update status.
> 2013-05-08 13:47:33,200 DEBUG
> [network.router.VirtualNetworkApplianceManagerImpl]
> (RouterStatusMonitor-1:null) Found 0 networks to update RvR status.
> 2013-05-08 13:47:33,280 DEBUG
> [network.router.VirtualNetworkApplianceManagerImpl]
> (RouterStatusMonitor-1:null) Found 0 routers to update status.
> 2013-05-08 13:47:33,281 DEBUG
> [network.router.VirtualNetworkApplianceManagerImpl]
> (RouterStatusMonitor-1:null) Found 0 networks to update RvR status.
> 2013-05-08 13:47:37,894 DEBUG [agent.manager.DirectAgentAttache]
> (DirectAgent-164:null) Seq 1-1674709490: Response Received:
> 2013-05-08 13:47:37,895 DEBUG [agent.transport.Request]
> (DirectAgent-164:null) Seq 1-1674709490: Processing: { Ans: , MgmtId:
> 7647994577963, via: 1, Ver: v1, Flags: 110,
> [{"Answer":{"result":true,"wait":0}},{"Answer":{"result":false,"details":"vm_data
> failed","wait":0}}] }
> 2013-05-08 13:47:37,895 DEBUG [agent.manager.AgentAttache]
> (DirectAgent-164:null) Seq 1-1674709490: No more commands found
> 2013-05-08 13:47:37,895 DEBUG [agent.transport.Request]
> (Job-Executor-18:job-39) Seq 1-1674709490: Received: { Ans: , MgmtId:
> 7647994577963, via: 1, Ver: v1, Flags: 110, { Answer, Answer } }
> 2013-05-08 13:47:37,895 INFO [cloud.vm.VirtualMachineManagerImpl]
> (Job-Executor-18:job-39) Unable to contact resource.
> com.cloud.exception.ResourceUnavailableException: Resource [DataCenter:1] is
> unreachable: Unable to apply userdata and password entry on router
> at
> com.cloud.network.router.VirtualNetworkApplianceManagerImpl.applyRules(VirtualNetworkApplianceManagerImpl.java:3496)
> at
> com.cloud.network.router.VirtualNetworkApplianceManagerImpl.applyUserData(VirtualNetworkApplianceManagerImpl.java:2790)
> at
> com.cloud.network.element.VirtualRouterElement.addPasswordAndUserdata(VirtualRouterElement.java:861)
> at
> com.cloud.network.NetworkManagerImpl.prepareElement(NetworkManagerImpl.java:1611)
> at
> com.cloud.network.NetworkManagerImpl.prepareNic(NetworkManagerImpl.java:1716)
> at
> com.cloud.network.NetworkManagerImpl.prepare(NetworkManagerImpl.java:1657)
> at
> com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:799)
> at
> com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:518)
> at
> org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.deployVirtualMachine(VMEntityManagerImpl.java:227)
> at
> org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.deploy(VirtualMachineEntityImpl.java:209)
> at
> com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3132)
> at
> com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2676)
> at
> com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2662)
> at
> com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
> at
> org.apache.cloudstack.api.command.user.vm.DeployVMCmd.execute(DeployVMCmd.java:413)
> at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:155)
> at
> com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:437)
> at
> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
> at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
> at java.util.concurrent.FutureTask.run(FutureTask.java:166)
> at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
> at java.lang.Thread.run(Thread.java:679)
> SMlog:
> [26123] 2013-05-08 13:59:58.331294 #### VMOPS enter gethostvmstats ####
> [26123] 2013-05-08 13:59:58.338405 #### VMOPS exit gethostvmstats ####
> [26085] 2013-05-08 13:59:59.340096 pread SUCCESS
> [26085] 2013-05-08 13:59:59.340570 ['/bin/bash',
> '/opt/xensource/bin/vm_data.sh', '-r', '169.254.0.235', '-v',
> '10.223.161.116', '-F', 'metadata', '-f', 'public-ipv4', '-d',
> '/tmp/tmpJBudVj']
> [26085] 2013-05-08 14:00:00.386719 pread SUCCESS
> [26085] 2013-05-08 14:00:00.387134 ['/bin/bash',
> '/opt/xensource/bin/vm_data.sh', '-r', '169.254.0.235', '-v',
> '10.223.161.116', '-F', 'metadata', '-f', 'cloud-identifier', '-d',
> '/tmp/tmpoWFBV3']
> [26085] 2013-05-08 14:00:01.472682 pread SUCCESS
> [26085] 2013-05-08 14:00:01.473200 ['/bin/bash',
> '/opt/xensource/bin/vm_data.sh', '-r', '169.254.0.235', '-v',
> '10.223.161.116', '-F', 'metadata', '-f', 'instance-id', '-d',
> '/tmp/tmpcpws9N']
> [26085] 2013-05-08 14:00:02.520907 pread SUCCESS
> [26085] 2013-05-08 14:00:02.521324 ['/bin/bash',
> '/opt/xensource/bin/vm_data.sh', '-r', '169.254.0.235', '-v',
> '10.223.161.116', '-F', 'metadata', '-f', 'local-hostname', '-d',
> '/tmp/tmpzKLxx2']
> [26085] 2013-05-08 14:00:03.564697 pread SUCCESS
> [26085] 2013-05-08 14:00:03.565189 ['/bin/bash',
> '/opt/xensource/bin/vm_data.sh', '-r', '169.254.0.235', '-v',
> '10.223.161.116', '-F', 'metadata', '-f', 'service-offering', '-d',
> '/tmp/tmpFeWX7A']
> [26085] 2013-05-08 14:00:04.607330 pread SUCCESS
> [26085] 2013-05-08 14:00:04.607759 ['/bin/bash',
> '/opt/xensource/bin/vm_data.sh', '-r', '169.254.0.235', '-v',
> '10.223.161.116', '-F', 'metadata', '-f', 'local-ipv4', '-d',
> '/tmp/tmpQKWrv1']
> [26085] 2013-05-08 14:00:06.618755 pread SUCCESS
> [26085] 2013-05-08 14:00:06.619178 ['/bin/bash',
> '/opt/xensource/bin/vm_data.sh', '-r', '169.254.0.235', '-v',
> '10.223.161.116', '-F', 'metadata', '-f', 'vm-id', '-d', '/tmp/tmpx4GMbA']
> [26085] 2013-05-08 14:00:07.663325 pread SUCCESS
> [26085] 2013-05-08 14:00:07.663803 vmdata failed to write tempfile
> [26085] 2013-05-08 14:00:07.663902 #### VMOPS exit vm_data ####
> [26332] 2013-05-08 14:00:08.770348 #### VMOPS enter saveDhcpEntry ####
> [26332] 2013-05-08 14:00:08.770465 ['/bin/bash',
> '/opt/xensource/bin/dhcp_entry.sh', '-r', '169.254.0.235', '-v',
> '10.223.161.116', '-m', '06:3f:4a:00:00:22', '-n', 'yo-userdata', '-d',
> '10.223.161.65', '-N', '10.223.161.110']
> [26332] 2013-05-08 14:00:08.976660 pread SUCCESS
> [26332] 2013-05-08 14:00:08.976803 #### VMOPS exit saveDhcpEntry ####
> [26340] 2013-05-08 14:00:09.223517 #### VMOPS enter savePassword ####
> [26340] 2013-05-08 14:00:09.223645 ['/bin/bash',
> '/opt/xensource/bin/save_password_to_domr.sh', '-r', '169.254.0.235', '-v',
> '10.223.161.116', '-p', 'fnirq_cnffjbeq', 'yo-userdata']
> [26340] 2013-05-08 14:00:09.490840 pread SUCCESS
> [26340] 2013-05-08 14:00:09.490982 #### VMOPS exit savePassword ####
> [26352] 2013-05-08 14:00:09.707671 #### VMOPS enter vm_data ####
> [26352] 2013-05-08 14:00:09.707766 adding vmdata for VM with IP:
> 10.223.161.116 to router with IP: 169.254.0.235
> [26352] 2013-05-08 14:00:09.708213 ['/bin/bash',
> '/opt/xensource/bin/vm_data.sh', '-r', '169.254.0.235', '-v',
> '10.223.161.116', '-F', 'metadata', '-f', 'public-hostname', '-d',
> '/tmp/tmpKQGUUj']
> [26352] 2013-05-08 14:00:10.747940 pread SUCCESS
> [26352] 2013-05-08 14:00:10.748346 ['/bin/bash',
> '/opt/xensource/bin/vm_data.sh', '-r', '169.254.0.235', '-v',
> '10.223.161.116', '-F', 'metadata', '-f', 'availability-zone', '-d',
> '/tmp/tmprXvDCW']
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira
