cloudstack-issues mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Sangeetha Hariharan (JIRA)" <j...@apache.org>
Subject [jira] [Updated] (CLOUDSTACK-2397) Not able to deploy a Vm with userdata in Shared network.
Date Wed, 08 May 2013 21:29:15 GMT

     [ https://issues.apache.org/jira/browse/CLOUDSTACK-2397?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]

Sangeetha Hariharan updated CLOUDSTACK-2397:
--------------------------------------------

    Description: 
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']


  was:
Steps to reproduce the problem:

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']


    
> Not able to deploy a Vm with userdata in Shared 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
>             Fix For: 4.2.0
>
>
> 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

Mime
View raw message