cloudstack-issues mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Animesh Chaturvedi (JIRA)" <j...@apache.org>
Subject [jira] [Updated] (CLOUDSTACK-4577) VMWare:Volumes: Unexpected exception while executing org.apache.cloudstack.api.command.user.volume.ResizeVolumeCmd java.lang.NullPointerException
Date Wed, 27 Nov 2013 22:50:36 GMT

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

Animesh Chaturvedi updated CLOUDSTACK-4577:
-------------------------------------------

    Fix Version/s: 4.3.0

> VMWare:Volumes: Unexpected exception while executing org.apache.cloudstack.api.command.user.volume.ResizeVolumeCmd
java.lang.NullPointerException
> -------------------------------------------------------------------------------------------------------------------------------------------------
>
>                 Key: CLOUDSTACK-4577
>                 URL: https://issues.apache.org/jira/browse/CLOUDSTACK-4577
>             Project: CloudStack
>          Issue Type: Bug
>      Security Level: Public(Anyone can view this level - this is the default.) 
>          Components: VMware, Volumes
>    Affects Versions: 4.2.1
>         Environment: VMWare,
> 5 Primary; 2 Zone wide and Rest Cluster.
> Attach Data Disk and attempt a Re-size.
>            Reporter: Parth Jagirdar
>            Priority: Critical
>             Fix For: 4.3.0
>
>
> Logs attached.
> 2013-08-30 16:12:14,513 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-8:null)
SeqA 9-1571: Processing Seq 9-1571:  { Cmd , MgmtId: -1, via: 9, Ver: v1, Flags: 11, [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":30,"_loadInfo":"{\n
 \"connections\": []\n}","wait":0}}] }
> 2013-08-30 16:12:14,520 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-8:null)
SeqA 9-1571: Sending Seq 9-1571:  { Ans: , MgmtId: 7471666038533, via: 9, Ver: v1, Flags:
100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
> 2013-08-30 16:12:18,099 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-10:null)
Ping from 10
> 2013-08-30 16:12:24,514 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-11:null)
SeqA 9-1572: Processing Seq 9-1572:  { Cmd , MgmtId: -1, via: 9, Ver: v1, Flags: 11, [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":30,"_loadInfo":"{\n
 \"connections\": []\n}","wait":0}}] }
> 2013-08-30 16:12:24,523 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-11:null)
SeqA 9-1572: Sending Seq 9-1572:  { Ans: , MgmtId: 7471666038533, via: 9, Ver: v1, Flags:
100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
> 2013-08-30 16:12:34,514 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-12:null)
SeqA 9-1573: Processing Seq 9-1573:  { Cmd , MgmtId: -1, via: 9, Ver: v1, Flags: 11, [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":30,"_loadInfo":"{\n
 \"connections\": []\n}","wait":0}}] }
> 2013-08-30 16:12:34,520 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-12:null)
SeqA 9-1573: Sending Seq 9-1573:  { Ans: , MgmtId: 7471666038533, via: 9, Ver: v1, Flags:
100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
> 2013-08-30 16:12:34,839 DEBUG [cloud.server.StatsCollector] (StatsCollector-1:null) HostStatsCollector
is running...
> 2013-08-30 16:12:34,849 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-492:null)
Seq 1-1168048937: Executing request
> 2013-08-30 16:12:34,877 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-492:null)
Seq 1-1168048937: Response Received:
> 2013-08-30 16:12:34,877 DEBUG [agent.transport.Request] (StatsCollector-1:null) Seq 1-1168048937:
Received:  { Ans: , MgmtId: 7471666038533, via: 1, Ver: v1, Flags: 10, { GetHostStatsAnswer
} }
> 2013-08-30 16:12:34,918 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-493:null)
Seq 6-580518619: Executing request
> 2013-08-30 16:12:34,940 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-493:null)
Seq 6-580518619: Response Received:
> 2013-08-30 16:12:34,940 DEBUG [agent.transport.Request] (StatsCollector-1:null) Seq 6-580518619:
Received:  { Ans: , MgmtId: 7471666038533, via: 6, Ver: v1, Flags: 10, { GetHostStatsAnswer
} }
> 2013-08-30 16:12:34,957 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-494:null)
Seq 8-2005992046: Executing request
> 2013-08-30 16:12:34,974 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-494:null)
Seq 8-2005992046: Response Received:
> 2013-08-30 16:12:34,975 DEBUG [agent.transport.Request] (StatsCollector-1:null) Seq 8-2005992046:
Received:  { Ans: , MgmtId: 7471666038533, via: 8, Ver: v1, Flags: 10, { GetHostStatsAnswer
} }
> 2013-08-30 16:12:35,099 DEBUG [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null)
Zone 1 is ready to launch secondary storage VM
> 2013-08-30 16:12:35,261 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:null)
Zone 1 is ready to launch console proxy
> 2013-08-30 16:12:36,129 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null)
Found 2 routers to update status.
> 2013-08-30 16:12:36,131 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null)
Found 0 networks to update RvR status.
> 2013-08-30 16:12:36,229 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null)
Found 2 routers to update status.
> 2013-08-30 16:12:36,230 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null)
Found 0 networks to update RvR status.
> 2013-08-30 16:12:44,514 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-13:null)
SeqA 9-1574: Processing Seq 9-1574:  { Cmd , MgmtId: -1, via: 9, Ver: v1, Flags: 11, [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":30,"_loadInfo":"{\n
 \"connections\": []\n}","wait":0}}] }
> 2013-08-30 16:12:44,520 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-13:null)
SeqA 9-1574: Sending Seq 9-1574:  { Ans: , MgmtId: 7471666038533, via: 9, Ver: v1, Flags:
100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
> 2013-08-30 16:12:49,890 DEBUG [cloud.server.StatsCollector] (StatsCollector-2:null) StorageCollector
is running...
> 2013-08-30 16:12:49,967 DEBUG [agent.transport.Request] (StatsCollector-2:null) Seq 10-1925054692:
Received:  { Ans: , MgmtId: 7471666038533, via: 10, Ver: v1, Flags: 10, { GetStorageStatsAnswer
} }
> 2013-08-30 16:12:49,974 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-216:null)
Seq 1-1168048938: Executing request
> 2013-08-30 16:12:50,020 DEBUG [vmware.resource.VmwareResource] (DirectAgent-216:10.223.59.66)
Datastore summary info, storageId: d89e306d-88e8-3997-ade6-fa97fed423bf, localPath: /export/home/chandan/307PB-195-103/primary1,
poolType: NetworkFilesystem, capacity: 11810778316800, free: 4331362349056, used: 7479415967744
> 2013-08-30 16:12:50,020 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-216:null)
Seq 1-1168048938: Response Received:
> 2013-08-30 16:12:50,021 DEBUG [agent.transport.Request] (StatsCollector-2:null) Seq 1-1168048938:
Received:  { Ans: , MgmtId: 7471666038533, via: 1, Ver: v1, Flags: 10, { GetStorageStatsAnswer
} }
> 2013-08-30 16:12:50,025 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-216:null)
Seq 6-580518620: Executing request
> 2013-08-30 16:12:50,053 DEBUG [vmware.resource.VmwareResource] (DirectAgent-216:10.223.57.66)
Datastore summary info, storageId: 96bc10ee-70b3-3d20-a60c-c068a024b3a7, localPath: /export/home/chandan/307PB-195-103/primary2,
poolType: NetworkFilesystem, capacity: 11810778316800, free: 4328890368000, used: 7481887948800
> 2013-08-30 16:12:50,054 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-216:null)
Seq 6-580518620: Response Received:
> 2013-08-30 16:12:50,054 DEBUG [agent.transport.Request] (StatsCollector-2:null) Seq 6-580518620:
Received:  { Ans: , MgmtId: 7471666038533, via: 6, Ver: v1, Flags: 10, { GetStorageStatsAnswer
} }
> 2013-08-30 16:12:50,060 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-216:null)
Seq 8-2005992047: Executing request
> 2013-08-30 16:12:50,101 DEBUG [vmware.resource.VmwareResource] (DirectAgent-216:10.223.59.67)
Datastore summary info, storageId: 9de17e9b-2280-328b-b1b2-e662e7253c3f, localPath: /export/home/chandan/307PB-195-103/primary4,
poolType: NetworkFilesystem, capacity: 11810778316800, free: 4324465197056, used: 7486313119744
> 2013-08-30 16:12:50,102 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-216:null)
Seq 8-2005992047: Response Received:
> 2013-08-30 16:12:50,102 DEBUG [agent.transport.Request] (StatsCollector-2:null) Seq 8-2005992047:
Received:  { Ans: , MgmtId: 7471666038533, via: 8, Ver: v1, Flags: 10, { GetStorageStatsAnswer
} }
> 2013-08-30 16:12:50,107 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-216:null)
Seq 1-1168048939: Executing request
> 2013-08-30 16:12:50,137 DEBUG [vmware.resource.VmwareResource] (DirectAgent-216:10.223.59.66)
Datastore summary info, storageId: 5420eab7-d6a1-31fa-958e-b10bd82dc581, localPath: /export/home/chandan/307PB-195-103/primary5,
poolType: NetworkFilesystem, capacity: 11810778316800, free: 4331539972096, used: 7479238344704
> 2013-08-30 16:12:50,137 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-216:null)
Seq 1-1168048939: Response Received:
> 2013-08-30 16:12:50,138 DEBUG [agent.transport.Request] (StatsCollector-2:null) Seq 1-1168048939:
Received:  { Ans: , MgmtId: 7471666038533, via: 1, Ver: v1, Flags: 10, { GetStorageStatsAnswer
} }
> 2013-08-30 16:12:54,066 DEBUG [cloud.server.StatsCollector] (StatsCollector-1:null) VmStatsCollector
is running...
> 2013-08-30 16:12:54,082 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-495:null)
Seq 1-1168048940: Executing request
> 2013-08-30 16:12:54,225 DEBUG [vmware.mo.HostMO] (DirectAgent-495:10.223.59.66) find
VM i-3-18-VMWAREFORWARD on host
> 2013-08-30 16:12:54,226 INFO  [vmware.mo.HostMO] (DirectAgent-495:10.223.59.66) VM i-3-18-VMWAREFORWARD
not found in host cache
> 2013-08-30 16:12:54,226 DEBUG [vmware.mo.HostMO] (DirectAgent-495:10.223.59.66) load
VM cache on host
> 2013-08-30 16:12:54,242 DEBUG [vmware.mo.HostMO] (DirectAgent-495:10.223.59.66) find
VM i-2-36-VMWAREFORWARD on host
> 2013-08-30 16:12:54,242 DEBUG [vmware.mo.HostMO] (DirectAgent-495:10.223.59.66) VM i-2-36-VMWAREFORWARD
found in host cache
> 2013-08-30 16:12:54,245 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-495:null)
Seq 1-1168048940: Response Received:
> 2013-08-30 16:12:54,246 DEBUG [agent.transport.Request] (StatsCollector-1:null) Seq 1-1168048940:
Received:  { Ans: , MgmtId: 7471666038533, via: 1, Ver: v1, Flags: 10, { GetVmStatsAnswer
} }
> 2013-08-30 16:12:54,259 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-496:null)
Seq 6-580518621: Executing request
> 2013-08-30 16:12:54,352 DEBUG [vmware.mo.HostMO] (DirectAgent-496:10.223.57.66) find
VM i-3-27-VMWAREFORWARD on host
> 2013-08-30 16:12:54,352 INFO  [vmware.mo.HostMO] (DirectAgent-496:10.223.57.66) VM i-3-27-VMWAREFORWARD
not found in host cache
> 2013-08-30 16:12:54,352 DEBUG [vmware.mo.HostMO] (DirectAgent-496:10.223.57.66) load
VM cache on host
> 2013-08-30 16:12:54,369 DEBUG [vmware.mo.HostMO] (DirectAgent-496:10.223.57.66) find
VM i-3-28-VMWAREFORWARD on host
> 2013-08-30 16:12:54,369 DEBUG [vmware.mo.HostMO] (DirectAgent-496:10.223.57.66) VM i-3-28-VMWAREFORWARD
found in host cache
> 2013-08-30 16:12:54,374 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-496:null)
Seq 6-580518621: Response Received:
> 2013-08-30 16:12:54,374 DEBUG [agent.transport.Request] (StatsCollector-1:null) Seq 6-580518621:
Received:  { Ans: , MgmtId: 7471666038533, via: 6, Ver: v1, Flags: 10, { GetVmStatsAnswer
} }
> 2013-08-30 16:12:54,384 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-43:null)
Seq 8-2005992048: Executing request
> 2013-08-30 16:12:54,459 DEBUG [vmware.mo.HostMO] (DirectAgent-43:10.223.59.67) find VM
i-3-20-VMWAREFORWARD on host
> 2013-08-30 16:12:54,459 INFO  [vmware.mo.HostMO] (DirectAgent-43:10.223.59.67) VM i-3-20-VMWAREFORWARD
not found in host cache
> 2013-08-30 16:12:54,459 DEBUG [vmware.mo.HostMO] (DirectAgent-43:10.223.59.67) load VM
cache on host
> 2013-08-30 16:12:54,475 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-43:null)
Seq 8-2005992048: Response Received:
> 2013-08-30 16:12:54,476 DEBUG [agent.transport.Request] (StatsCollector-1:null) Seq 8-2005992048:
Received:  { Ans: , MgmtId: 7471666038533, via: 8, Ver: v1, Flags: 10, { GetVmStatsAnswer
} }
> 2013-08-30 16:12:54,515 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-15:null)
SeqA 9-1575: Processing Seq 9-1575:  { Cmd , MgmtId: -1, via: 9, Ver: v1, Flags: 11, [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":30,"_loadInfo":"{\n
 \"connections\": []\n}","wait":0}}] }
> 2013-08-30 16:12:54,522 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-15:null)
SeqA 9-1575: Sending Seq 9-1575:  { Ans: , MgmtId: 7471666038533, via: 9, Ver: v1, Flags:
100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
> 2013-08-30 16:12:56,477 DEBUG [cloud.api.ApiServlet] (catalina-exec-11:null) ===START===
 10.215.2.19 -- GET  command=listDiskOfferings&response=json&sessionkey=iN1%2BFv5iLGYuxcPQU06GRgdBcU0%3D&_=1377904759038
> 2013-08-30 16:12:56,490 DEBUG [cloud.api.ApiServlet] (catalina-exec-11:null) ===END===
 10.215.2.19 -- GET  command=listDiskOfferings&response=json&sessionkey=iN1%2BFv5iLGYuxcPQU06GRgdBcU0%3D&_=1377904759038
> 2013-08-30 16:12:58,202 DEBUG [cloud.api.ApiServlet] (catalina-exec-1:null) ===START===
 10.215.2.19 -- GET  command=resizeVolume&id=8c27247d-e1e6-4768-92f4-d2b4e019223c&shrinkok=false&diskofferingid=80982db4-adba-48bb-ad0e-2a0c281b59cd&response=json&sessionkey=iN1%2BFv5iLGYuxcPQU06GRgdBcU0%3D&_=1377904760765
> 2013-08-30 16:12:58,231 DEBUG [cloud.async.AsyncJobManagerImpl] (catalina-exec-1:null)
submit async job-106 = [ e80aebbe-df3b-4c02-bdfa-dc778aad0d72 ], details: AsyncJobVO {id:106,
userId: 2, accountId: 2, sessionKey: null, instanceType: Volume, instanceId: null, cmd: org.apache.cloudstack.api.command.user.volume.ResizeVolumeCmd,
cmdOriginator: null, cmdInfo: {"response":"json","id":"8c27247d-e1e6-4768-92f4-d2b4e019223c","sessionkey":"iN1+Fv5iLGYuxcPQU06GRgdBcU0\u003d","shrinkok":"false","cmdEventType":"VOLUME.RESIZE","ctxUserId":"2","httpmethod":"GET","_":"1377904760765","ctxAccountId":"2","diskofferingid":"80982db4-adba-48bb-ad0e-2a0c281b59cd","ctxStartEventId":"877"},
cmdVersion: 0, callbackType: 0, callbackAddress: null, status: 0, processStatus: 0, resultCode:
0, result: null, initMsid: 7471666038533, completeMsid: null, lastUpdated: null, lastPolled:
null, created: null}
> 2013-08-30 16:12:58,232 DEBUG [cloud.api.ApiServlet] (catalina-exec-1:null) ===END===
 10.215.2.19 -- GET  command=resizeVolume&id=8c27247d-e1e6-4768-92f4-d2b4e019223c&shrinkok=false&diskofferingid=80982db4-adba-48bb-ad0e-2a0c281b59cd&response=json&sessionkey=iN1%2BFv5iLGYuxcPQU06GRgdBcU0%3D&_=1377904760765
> 2013-08-30 16:12:58,234 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-31:job-106
= [ e80aebbe-df3b-4c02-bdfa-dc778aad0d72 ]) Executing org.apache.cloudstack.api.command.user.volume.ResizeVolumeCmd
for job-106 = [ e80aebbe-df3b-4c02-bdfa-dc778aad0d72 ]
> 2013-08-30 16:12:58,301 ERROR [cloud.async.AsyncJobManagerImpl] (Job-Executor-31:job-106
= [ e80aebbe-df3b-4c02-bdfa-dc778aad0d72 ]) Unexpected exception while executing org.apache.cloudstack.api.command.user.volume.ResizeVolumeCmd
> java.lang.NullPointerException
>         at com.cloud.storage.VolumeManagerImpl.resizeVolume(VolumeManagerImpl.java:1147)
>         at com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
>         at com.cloud.storage.VolumeManagerImpl.resizeVolume(VolumeManagerImpl.java:183)
>         at org.apache.cloudstack.api.command.user.volume.ResizeVolumeCmd.execute(ResizeVolumeCmd.java:137)
>         at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:158)
>         at com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:531)
>         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)
> 2013-08-30 16:12:58,303 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-31:job-106
= [ e80aebbe-df3b-4c02-bdfa-dc778aad0d72 ]) Complete async job-106 = [ e80aebbe-df3b-4c02-bdfa-dc778aad0d72
], jobStatus: 2, resultCode: 530, result: Error Code: 530 Error text: null
> 2013-08-30 16:12:58,455 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-496:null)
Ping from 8
> 2013-08-30 16:12:58,476 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-206:null)
Ping from 1
> 2013-08-30 16:12:59,041 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-43:null)
Ping from 6
> 2013-08-30 16:13:01,368 DEBUG [cloud.api.ApiServlet] (catalina-exec-8:null) ===START===
 10.215.2.19 -- GET  command=queryAsyncJobResult&jobId=e80aebbe-df3b-4c02-bdfa-dc778aad0d72&response=json&sessionkey=iN1%2BFv5iLGYuxcPQU06GRgdBcU0%3D&_=1377904763932
> 2013-08-30 16:13:01,375 DEBUG [cloud.async.AsyncJobManagerImpl] (catalina-exec-8:null)
Async job-106 = [ e80aebbe-df3b-4c02-bdfa-dc778aad0d72 ] completed
> 2013-08-30 16:13:01,380 DEBUG [cloud.api.ApiServlet] (catalina-exec-8:null) ===END===
 10.215.2.19 -- GET  command=queryAsyncJobResult&jobId=e80aebbe-df3b-4c02-bdfa-dc778aad0d72&response=json&sessionkey=iN1%2BFv5iLGYuxcPQU06GRgdBcU0%3D&_=1377904763932
> 2013-08-30 16:13:04,515 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-1:null)
SeqA 9-1576: Processing Seq 9-1576:  { Cmd , MgmtId: -1, via: 9, Ver: v1, Flags: 11, [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":30,"_loadInfo":"{\n
 \"connections\": []\n}","wait":0}}] }
> 2013-08-30 16:13:04,522 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-1:null)
SeqA 9-1576: Sending Seq 9-1576:  { Ans: , MgmtId: 7471666038533, via: 9, Ver: v1, Flags:
100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
> 2013-08-30 16:13:05,101 DEBUG [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null)
Zone 1 is ready to launch secondary storage VM
> 2013-08-30 16:13:05,252 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:null)
Zone 1 is ready to launch console proxy
> 2013-08-30 16:13:06,130 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null)
Found 2 routers to update status.
> 2013-08-30 16:13:06,132 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null)
Found 0 networks to update RvR status.
> 2013-08-30 16:13:06,229 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null)
Found 2 routers to update status.
> 2013-08-30 16:13:06,231 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null)
Found 0 networks to update RvR status.
> 2013-08-30 16:13:08,546 DEBUG [cloud.api.ApiServlet] (catalina-exec-14:null) ===START===
 10.215.2.19 -- GET  command=detachVolume&id=8c27247d-e1e6-4768-92f4-d2b4e019223c&response=json&sessionkey=iN1%2BFv5iLGYuxcPQU06GRgdBcU0%3D&_=1377904771108
> 2013-08-30 16:13:08,572 DEBUG [cloud.async.AsyncJobManagerImpl] (catalina-exec-14:null)
submit async job-107 = [ 33d8f0b0-f545-4588-a845-39044a61db0b ], details: AsyncJobVO {id:107,
userId: 2, accountId: 2, sessionKey: null, instanceType: Volume, instanceId: 44, cmd: org.apache.cloudstack.api.command.user.volume.DetachVolumeCmd,
cmdOriginator: null, cmdInfo: {"response":"json","id":"8c27247d-e1e6-4768-92f4-d2b4e019223c","sessionkey":"iN1+Fv5iLGYuxcPQU06GRgdBcU0\u003d","cmdEventType":"VOLUME.DETACH","ctxUserId":"2","httpmethod":"GET","_":"1377904771108","ctxAccountId":"2","ctxStartEventId":"880"},
cmdVersion: 0, callbackType: 0, callbackAddress: null, status: 0, processStatus: 0, resultCode:
0, result: null, initMsid: 7471666038533, completeMsid: null, lastUpdated: null, lastPolled:
null, created: null}
> 2013-08-30 16:13:08,574 DEBUG [cloud.api.ApiServlet] (catalina-exec-14:null) ===END===
 10.215.2.19 -- GET  command=detachVolume&id=8c27247d-e1e6-4768-92f4-d2b4e019223c&response=json&sessionkey=iN1%2BFv5iLGYuxcPQU06GRgdBcU0%3D&_=1377904771108
> 2013-08-30 16:13:08,576 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-32:job-107
= [ 33d8f0b0-f545-4588-a845-39044a61db0b ]) Executing org.apache.cloudstack.api.command.user.volume.DetachVolumeCmd
for job-107 = [ 33d8f0b0-f545-4588-a845-39044a61db0b ]
> 2013-08-30 16:13:08,603 DEBUG [agent.transport.Request] (Job-Executor-32:job-107 = [
33d8f0b0-f545-4588-a845-39044a61db0b ]) Seq 1-1168048941: Sending  { Cmd , MgmtId: 7471666038533,
via: 1, Ver: v1, Flags: 100011, [{"org.apache.cloudstack.storage.command.DettachCommand":{"disk":{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"8c27247d-e1e6-4768-92f4-d2b4e019223c","volumeType":"DATADISK","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"9de17e9b-2280-328b-b1b2-e662e7253c3f","id":204,"poolType":"NetworkFilesystem","host":"10.223.110.232","path":"/export/home/chandan/307PB-195-103/primary4","port":2049}},"name":"new-vol","size":1073741824,"path":"5f480f78ae804e55b0e9729a25ab817f","volumeId":44,"vmName":"i-2-36-VMWAREFORWARD","accountId":2,"format":"OVA","id":44,"hypervisorType":"VMware"}},"diskSeq":2,"type":"DATADISK"},"vmName":"i-2-36-VMWAREFORWARD","_managed":false,"_storageHost":"10.223.110.232","_storagePort":2049,"wait":0}}]
}
> 2013-08-30 16:13:08,604 DEBUG [agent.transport.Request] (Job-Executor-32:job-107 = [
33d8f0b0-f545-4588-a845-39044a61db0b ]) Seq 1-1168048941: Executing:  { Cmd , MgmtId: 7471666038533,
via: 1, Ver: v1, Flags: 100011, [{"org.apache.cloudstack.storage.command.DettachCommand":{"disk":{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"8c27247d-e1e6-4768-92f4-d2b4e019223c","volumeType":"DATADISK","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"9de17e9b-2280-328b-b1b2-e662e7253c3f","id":204,"poolType":"NetworkFilesystem","host":"10.223.110.232","path":"/export/home/chandan/307PB-195-103/primary4","port":2049}},"name":"new-vol","size":1073741824,"path":"5f480f78ae804e55b0e9729a25ab817f","volumeId":44,"vmName":"i-2-36-VMWAREFORWARD","accountId":2,"format":"OVA","id":44,"hypervisorType":"VMware"}},"diskSeq":2,"type":"DATADISK"},"vmName":"i-2-36-VMWAREFORWARD","_managed":false,"_storageHost":"10.223.110.232","_storagePort":2049,"wait":0}}]
}
> 2013-08-30 16:13:08,604 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-498:null)
Seq 1-1168048941: Executing request
> 2013-08-30 16:13:08,620 DEBUG [vmware.mo.HostMO] (DirectAgent-498:10.223.59.66) find
VM i-2-36-VMWAREFORWARD on host
> 2013-08-30 16:13:08,620 INFO  [vmware.mo.HostMO] (DirectAgent-498:10.223.59.66) VM i-2-36-VMWAREFORWARD
not found in host cache
> 2013-08-30 16:13:08,620 DEBUG [vmware.mo.HostMO] (DirectAgent-498:10.223.59.66) load
VM cache on host
> 2013-08-30 16:13:08,678 INFO  [vmware.mo.DatastoreMO] (DirectAgent-498:10.223.59.66)
Search file 5f480f78ae804e55b0e9729a25ab817f.vmdk on [9de17e9b2280328bb1b2e662e7253c3f]
> 2013-08-30 16:13:08,697 INFO  [vmware.mo.DatastoreMO] (DirectAgent-498:10.223.59.66)
File [9de17e9b2280328bb1b2e662e7253c3f] 5f480f78ae804e55b0e9729a25ab817f.vmdk does not exist
on datastore
> 2013-08-30 16:13:08,705 INFO  [vmware.mo.VirtualMachineMO] (DirectAgent-498:10.223.59.66)
Look for disk device info from volume : [9de17e9b2280328bb1b2e662e7253c3f] i-2-36-VMWAREFORWARD/5f480f78ae804e55b0e9729a25ab817f.vmdk
> 2013-08-30 16:13:08,706 INFO  [vmware.mo.VirtualMachineMO] (DirectAgent-498:10.223.59.66)
Test against disk device, controller key: 1000, unit number: 0
> 2013-08-30 16:13:08,706 INFO  [vmware.mo.VirtualMachineMO] (DirectAgent-498:10.223.59.66)
Test against disk backing : [9de17e9b2280328bb1b2e662e7253c3f] i-2-36-VMWAREFORWARD/282bc8898c8c4ccdaa515464ad7fec4a.vmdk
> 2013-08-30 16:13:08,706 INFO  [vmware.mo.VirtualMachineMO] (DirectAgent-498:10.223.59.66)
Test against disk device, controller key: 200, unit number: 1
> 2013-08-30 16:13:08,706 INFO  [vmware.mo.VirtualMachineMO] (DirectAgent-498:10.223.59.66)
Test against disk backing : [9de17e9b2280328bb1b2e662e7253c3f] i-2-36-VMWAREFORWARD/ROOT-36.vmdk
> 2013-08-30 16:13:08,706 INFO  [vmware.mo.VirtualMachineMO] (DirectAgent-498:10.223.59.66)
Test against disk backing : [9de17e9b2280328bb1b2e662e7253c3f] 31b1263bd2e735c5bdc2e964b291d76f/31b1263bd2e735c5bdc2e964b291d76f.vmdk
> 2013-08-30 16:13:08,706 INFO  [vmware.mo.VirtualMachineMO] (DirectAgent-498:10.223.59.66)
Test against disk device, controller key: 1000, unit number: 1
> 2013-08-30 16:13:08,706 INFO  [vmware.mo.VirtualMachineMO] (DirectAgent-498:10.223.59.66)
Test against disk backing : [9de17e9b2280328bb1b2e662e7253c3f] i-2-36-VMWAREFORWARD/5f480f78ae804e55b0e9729a25ab817f.vmdk
> 2013-08-30 16:13:08,706 INFO  [vmware.mo.VirtualMachineMO] (DirectAgent-498:10.223.59.66)
Disk backing : [9de17e9b2280328bb1b2e662e7253c3f] i-2-36-VMWAREFORWARD/5f480f78ae804e55b0e9729a25ab817f.vmdk
matches ==> scsi0:1
> 2013-08-30 16:13:08,713 INFO  [vmware.util.VmwareContext] (DirectAgent-498:10.223.59.66)
Connected, conn: sun.net.www.protocol.https.DelegateHttpsURLConnection:https://10.223.52.61/folder/i-2-36-VMWAREFORWARD/5f480f78ae804e55b0e9729a25ab817f.vmdk?dcPath=VMDC&dsName=9de17e9b2280328bb1b2e662e7253c3f,
retry: 0
> 2013-08-30 16:13:11,710 DEBUG [cloud.api.ApiServlet] (catalina-exec-5:null) ===START===
 10.215.2.19 -- GET  command=queryAsyncJobResult&jobId=33d8f0b0-f545-4588-a845-39044a61db0b&response=json&sessionkey=iN1%2BFv5iLGYuxcPQU06GRgdBcU0%3D&_=1377904774275
> 2013-08-30 16:13:11,734 DEBUG [cloud.api.ApiServlet] (catalina-exec-5:null) ===END===
 10.215.2.19 -- GET  command=queryAsyncJobResult&jobId=33d8f0b0-f545-4588-a845-39044a61db0b&response=json&sessionkey=iN1%2BFv5iLGYuxcPQU06GRgdBcU0%3D&_=1377904774275
> 2013-08-30 16:13:11,938 INFO  [vmware.util.VmwareContext] (DirectAgent-498:10.223.59.66)
Connected, conn: sun.net.www.protocol.https.DelegateHttpsURLConnection:https://10.223.52.61/folder/i-2-36-VMWAREFORWARD/i-2-36-VMWAREFORWARD.vmsd?dcPath=VMDC&dsName=9de17e9b2280328bb1b2e662e7253c3f,
retry: 0
> 2013-08-30 16:13:12,123 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-2:null)
Ping from 9
> 2013-08-30 16:13:12,562 WARN  [vmware.mo.VirtualMachineMO] (DirectAgent-498:10.223.59.66)
Snapshot descriptor file (vsd) does not exist anymore?
> 2013-08-30 16:13:12,571 INFO  [vmware.util.VmwareContext] (DirectAgent-498:10.223.59.66)
Connected, conn: sun.net.www.protocol.https.DelegateHttpsURLConnection:https://10.223.52.61/folder/i-2-36-VMWAREFORWARD/i-2-36-VMWAREFORWARD.vmsd?dcPath=VMDC&dsName=9de17e9b2280328bb1b2e662e7253c3f,
retry: 0
> 2013-08-30 16:13:13,154 INFO  [vmware.mo.DatastoreMO] (DirectAgent-498:10.223.59.66)
Search file 5f480f78ae804e55b0e9729a25ab817f.vmdk on [9de17e9b2280328bb1b2e662e7253c3f]
> 2013-08-30 16:13:13,173 INFO  [vmware.mo.DatastoreMO] (DirectAgent-498:10.223.59.66)
File [9de17e9b2280328bb1b2e662e7253c3f] 5f480f78ae804e55b0e9729a25ab817f.vmdk does not exist
on datastore
> 2013-08-30 16:13:13,173 INFO  [vmware.mo.DatastoreMO] (DirectAgent-498:10.223.59.66)
Searching file 5f480f78ae804e55b0e9729a25ab817f.vmdk in [9de17e9b2280328bb1b2e662e7253c3f]
> 2013-08-30 16:13:13,214 INFO  [vmware.mo.DatastoreMO] (DirectAgent-498:10.223.59.66)
Found file 5f480f78ae804e55b0e9729a25ab817f.vmdk in datastore at [9de17e9b2280328bb1b2e662e7253c3f]
i-2-36-VMWAREFORWARD/
> 2013-08-30 16:13:13,217 INFO  [vmware.mo.DatastoreMO] (DirectAgent-498:10.223.59.66)
Search file 5f480f78ae804e55b0e9729a25ab817f-flat.vmdk on [9de17e9b2280328bb1b2e662e7253c3f]
i-2-36-VMWAREFORWARD
> 2013-08-30 16:13:13,236 INFO  [vmware.mo.DatastoreMO] (DirectAgent-498:10.223.59.66)
File [9de17e9b2280328bb1b2e662e7253c3f] i-2-36-VMWAREFORWARD/5f480f78ae804e55b0e9729a25ab817f-flat.vmdk
exists on datastore
> 2013-08-30 16:13:13,236 INFO  [storage.resource.VmwareStorageLayoutHelper] (DirectAgent-498:10.223.59.66)
Fixup folder-synchronization. move [9de17e9b2280328bb1b2e662e7253c3f] i-2-36-VMWAREFORWARD/5f480f78ae804e55b0e9729a25ab817f-flat.vmdk
-> [9de17e9b2280328bb1b2e662e7253c3f] 5f480f78ae804e55b0e9729a25ab817f-flat.vmdk
> 2013-08-30 16:13:13,613 INFO  [vmware.mo.DatastoreMO] (DirectAgent-498:10.223.59.66)
Search file 5f480f78ae804e55b0e9729a25ab817f-delta.vmdk on [9de17e9b2280328bb1b2e662e7253c3f]
i-2-36-VMWAREFORWARD
> 2013-08-30 16:13:13,659 INFO  [vmware.mo.DatastoreMO] (DirectAgent-498:10.223.59.66)
File [9de17e9b2280328bb1b2e662e7253c3f] i-2-36-VMWAREFORWARD/5f480f78ae804e55b0e9729a25ab817f-delta.vmdk
does not exist on datastore
> 2013-08-30 16:13:13,660 INFO  [storage.resource.VmwareStorageLayoutHelper] (DirectAgent-498:10.223.59.66)
Fixup folder-synchronization. move [9de17e9b2280328bb1b2e662e7253c3f] i-2-36-VMWAREFORWARD/5f480f78ae804e55b0e9729a25ab817f.vmdk
-> [9de17e9b2280328bb1b2e662e7253c3f] 5f480f78ae804e55b0e9729a25ab817f.vmdk
> 2013-08-30 16:13:14,127 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-498:null)
Seq 1-1168048941: Response Received:
> 2013-08-30 16:13:14,127 DEBUG [agent.transport.Request] (DirectAgent-498:null) Seq 1-1168048941:
Processing:  { Ans: , MgmtId: 7471666038533, via: 1, Ver: v1, Flags: 10, [{"org.apache.cloudstack.storage.command.AttachAnswer":{"disk":{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"8c27247d-e1e6-4768-92f4-d2b4e019223c","volumeType":"DATADISK","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"9de17e9b-2280-328b-b1b2-e662e7253c3f","id":204,"poolType":"NetworkFilesystem","host":"10.223.110.232","path":"/export/home/chandan/307PB-195-103/primary4","port":2049}},"name":"new-vol","size":1073741824,"path":"5f480f78ae804e55b0e9729a25ab817f","volumeId":44,"vmName":"i-2-36-VMWAREFORWARD","accountId":2,"format":"OVA","id":44,"hypervisorType":"VMware"}},"diskSeq":2,"vdiUuid":"[9de17e9b2280328bb1b2e662e7253c3f]
i-2-36-VMWAREFORWARD/5f480f78ae804e55b0e9729a25ab817f.vmdk","type":"DATADISK"},"result":true,"wait":0}}]
}
> 2013-08-30 16:13:14,128 DEBUG [agent.transport.Request] (Job-Executor-32:job-107 = [
33d8f0b0-f545-4588-a845-39044a61db0b ]) Seq 1-1168048941: Received:  { Ans: , MgmtId: 7471666038533,
via: 1, Ver: v1, Flags: 10, { AttachAnswer } }
> 2013-08-30 16:13:14,150 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-32:job-107
= [ 33d8f0b0-f545-4588-a845-39044a61db0b ]) Complete async job-107 = [ 33d8f0b0-f545-4588-a845-39044a61db0b
], jobStatus: 1, resultCode: 0, result: org.apache.cloudstack.api.response.VolumeResponse@410b65cd
> 2013-08-30 16:13:14,157 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-32:job-107
= [ 33d8f0b0-f545-4588-a845-39044a61db0b ]) Done executing org.apache.cloudstack.api.command.user.volume.DetachVolumeCmd
for job-107 = [ 33d8f0b0-f545-4588-a845-39044a61db0b ]
> 2013-08-30 16:13:14,516 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-3:null)
SeqA 9-1578: Processing Seq 9-1578:  { Cmd , MgmtId: -1, via: 9, Ver: v1, Flags: 11, [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":30,"_loadInfo":"{\n
 \"connections\": []\n}","wait":0}}] }
> 2013-08-30 16:13:14,522 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-3:null)
SeqA 9-1578: Sending Seq 9-1578:  { Ans: , MgmtId: 7471666038533, via: 9, Ver: v1, Flags:
100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
> 2013-08-30 16:13:14,710 DEBUG [cloud.api.ApiServlet] (catalina-exec-4:null) ===START===
 10.215.2.19 -- GET  command=queryAsyncJobResult&jobId=33d8f0b0-f545-4588-a845-39044a61db0b&response=json&sessionkey=iN1%2BFv5iLGYuxcPQU06GRgdBcU0%3D&_=1377904777275
> 2013-08-30 16:13:14,722 DEBUG [cloud.async.AsyncJobManagerImpl] (catalina-exec-4:null)
Async job-107 = [ 33d8f0b0-f545-4588-a845-39044a61db0b ] completed
> 2013-08-30 16:13:14,729 DEBUG [cloud.api.ApiServlet] (catalina-exec-4:null) ===END===
 10.215.2.19 -- GET  command=queryAsyncJobResult&jobId=33d8f0b0-f545-4588-a845-39044a61db0b&response=json&sessionkey=iN1%2BFv5iLGYuxcPQU06GRgdBcU0%3D&_=1377904777275
> 2013-08-30 16:13:14,756 DEBUG [cloud.api.ApiServlet] (catalina-exec-13:null) ===START===
 10.215.2.19 -- GET  command=listVolumes&id=8c27247d-e1e6-4768-92f4-d2b4e019223c&response=json&sessionkey=iN1%2BFv5iLGYuxcPQU06GRgdBcU0%3D&_=1377904777320
> 2013-08-30 16:13:14,773 DEBUG [cloud.api.ApiServlet] (catalina-exec-13:null) ===END===
 10.215.2.19 -- GET  command=listVolumes&id=8c27247d-e1e6-4768-92f4-d2b4e019223c&response=json&sessionkey=iN1%2BFv5iLGYuxcPQU06GRgdBcU0%3D&_=1377904777320
> 2013-08-30 16:13:14,887 DEBUG [cloud.api.ApiServlet] (catalina-exec-7:null) ===START===
 10.215.2.19 -- GET  command=listTags&response=json&sessionkey=iN1%2BFv5iLGYuxcPQU06GRgdBcU0%3D&resourceId=8c27247d-e1e6-4768-92f4-d2b4e019223c&resourceType=Volume&listAll=true&_=1377904777450
> 2013-08-30 16:13:14,896 DEBUG [cloud.api.ApiServlet] (catalina-exec-7:null) ===END===
 10.215.2.19 -- GET  command=listTags&response=json&sessionkey=iN1%2BFv5iLGYuxcPQU06GRgdBcU0%3D&resourceId=8c27247d-e1e6-4768-92f4-d2b4e019223c&resourceType=Volume&listAll=true&_=1377904777450
> 2013-08-30 16:13:16,644 DEBUG [cloud.api.ApiServlet] (catalina-exec-22:null) ===START===
 10.215.2.19 -- GET  command=listDiskOfferings&response=json&sessionkey=iN1%2BFv5iLGYuxcPQU06GRgdBcU0%3D&_=1377904779208
> 2013-08-30 16:13:16,656 DEBUG [cloud.api.ApiServlet] (catalina-exec-22:null) ===END===
 10.215.2.19 -- GET  command=listDiskOfferings&response=json&sessionkey=iN1%2BFv5iLGYuxcPQU06GRgdBcU0%3D&_=1377904779208
> 2013-08-30 16:13:18,096 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-5:null)
Ping from 10
> 2013-08-30 16:13:19,540 DEBUG [cloud.api.ApiServlet] (catalina-exec-16:null) ===START===
 10.215.2.19 -- GET  command=listVolumes&response=json&sessionkey=iN1%2BFv5iLGYuxcPQU06GRgdBcU0%3D&listAll=true&page=1&pagesize=20&_=1377904782104
> 2013-08-30 16:13:19,560 DEBUG [cloud.api.ApiServlet] (catalina-exec-16:null) ===END===
 10.215.2.19 -- GET  command=listVolumes&response=json&sessionkey=iN1%2BFv5iLGYuxcPQU06GRgdBcU0%3D&listAll=true&page=1&pagesize=20&_=1377904782104
> 2013-08-30 16:13:20,685 DEBUG [cloud.api.ApiServlet] (catalina-exec-6:null) ===START===
 10.215.2.19 -- GET  command=listVolumes&id=8c27247d-e1e6-4768-92f4-d2b4e019223c&response=json&sessionkey=iN1%2BFv5iLGYuxcPQU06GRgdBcU0%3D&_=1377904783248
> 2013-08-30 16:13:20,702 DEBUG [cloud.api.ApiServlet] (catalina-exec-6:null) ===END===
 10.215.2.19 -- GET  command=listVolumes&id=8c27247d-e1e6-4768-92f4-d2b4e019223c&response=json&sessionkey=iN1%2BFv5iLGYuxcPQU06GRgdBcU0%3D&_=1377904783248
> 2013-08-30 16:13:20,805 DEBUG [cloud.api.ApiServlet] (catalina-exec-10:null) ===START===
 10.215.2.19 -- GET  command=listTags&response=json&sessionkey=iN1%2BFv5iLGYuxcPQU06GRgdBcU0%3D&resourceId=8c27247d-e1e6-4768-92f4-d2b4e019223c&resourceType=Volume&listAll=true&_=1377904783367
> 2013-08-30 16:13:20,815 DEBUG [cloud.api.ApiServlet] (catalina-exec-10:null) ===END===
 10.215.2.19 -- GET  command=listTags&response=json&sessionkey=iN1%2BFv5iLGYuxcPQU06GRgdBcU0%3D&resourceId=8c27247d-e1e6-4768-92f4-d2b4e019223c&resourceType=Volume&listAll=true&_=1377904783367
> 2013-08-30 16:13:21,994 DEBUG [cloud.api.ApiServlet] (catalina-exec-2:null) ===START===
 10.215.2.19 -- GET  command=listDiskOfferings&response=json&sessionkey=iN1%2BFv5iLGYuxcPQU06GRgdBcU0%3D&_=1377904784559
> 2013-08-30 16:13:22,006 DEBUG [cloud.api.ApiServlet] (catalina-exec-2:null) ===END===
 10.215.2.19 -- GET  command=listDiskOfferings&response=json&sessionkey=iN1%2BFv5iLGYuxcPQU06GRgdBcU0%3D&_=1377904784559
> 2013-08-30 16:13:24,516 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-6:null)
SeqA 9-1579: Processing Seq 9-1579:  { Cmd , MgmtId: -1, via: 9, Ver: v1, Flags: 11, [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":30,"_loadInfo":"{\n
 \"connections\": []\n}","wait":0}}] }
> 2013-08-30 16:13:24,524 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-6:null)
SeqA 9-1579: Sending Seq 9-1579:  { Ans: , MgmtId: 7471666038533, via: 9, Ver: v1, Flags:
100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
> 2013-08-30 16:13:26,021 DEBUG [cloud.api.ApiServlet] (catalina-exec-3:null) ===START===
 10.215.2.19 -- GET  command=resizeVolume&id=8c27247d-e1e6-4768-92f4-d2b4e019223c&shrinkok=false&diskofferingid=80982db4-adba-48bb-ad0e-2a0c281b59cd&response=json&sessionkey=iN1%2BFv5iLGYuxcPQU06GRgdBcU0%3D&_=1377904788583
> 2013-08-30 16:13:26,068 DEBUG [cloud.async.AsyncJobManagerImpl] (catalina-exec-3:null)
submit async job-108 = [ a35c80cf-a1f4-41f6-a97a-9dcb97776f4c ], details: AsyncJobVO {id:108,
userId: 2, accountId: 2, sessionKey: null, instanceType: Volume, instanceId: null, cmd: org.apache.cloudstack.api.command.user.volume.ResizeVolumeCmd,
cmdOriginator: null, cmdInfo: {"response":"json","id":"8c27247d-e1e6-4768-92f4-d2b4e019223c","sessionkey":"iN1+Fv5iLGYuxcPQU06GRgdBcU0\u003d","shrinkok":"false","cmdEventType":"VOLUME.RESIZE","ctxUserId":"2","httpmethod":"GET","_":"1377904788583","ctxAccountId":"2","diskofferingid":"80982db4-adba-48bb-ad0e-2a0c281b59cd","ctxStartEventId":"883"},
cmdVersion: 0, callbackType: 0, callbackAddress: null, status: 0, processStatus: 0, resultCode:
0, result: null, initMsid: 7471666038533, completeMsid: null, lastUpdated: null, lastPolled:
null, created: null}
> 2013-08-30 16:13:26,070 DEBUG [cloud.api.ApiServlet] (catalina-exec-3:null) ===END===
 10.215.2.19 -- GET  command=resizeVolume&id=8c27247d-e1e6-4768-92f4-d2b4e019223c&shrinkok=false&diskofferingid=80982db4-adba-48bb-ad0e-2a0c281b59cd&response=json&sessionkey=iN1%2BFv5iLGYuxcPQU06GRgdBcU0%3D&_=1377904788583
> 2013-08-30 16:13:26,073 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-33:job-108
= [ a35c80cf-a1f4-41f6-a97a-9dcb97776f4c ]) Executing org.apache.cloudstack.api.command.user.volume.ResizeVolumeCmd
for job-108 = [ a35c80cf-a1f4-41f6-a97a-9dcb97776f4c ]
> 2013-08-30 16:13:26,113 ERROR [cloud.async.AsyncJobManagerImpl] (Job-Executor-33:job-108
= [ a35c80cf-a1f4-41f6-a97a-9dcb97776f4c ]) Unexpected exception while executing org.apache.cloudstack.api.command.user.volume.ResizeVolumeCmd
> java.lang.NullPointerException
>         at com.cloud.storage.VolumeManagerImpl.resizeVolume(VolumeManagerImpl.java:1147)
>         at com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
>         at com.cloud.storage.VolumeManagerImpl.resizeVolume(VolumeManagerImpl.java:183)
>         at org.apache.cloudstack.api.command.user.volume.ResizeVolumeCmd.execute(ResizeVolumeCmd.java:137)
>         at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:158)
>         at com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:531)
>         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)
> 2013-08-30 16:13:26,116 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-33:job-108
= [ a35c80cf-a1f4-41f6-a97a-9dcb97776f4c ]) Complete async job-108 = [ a35c80cf-a1f4-41f6-a97a-9dcb97776f4c
], jobStatus: 2, resultCode: 530, result: Error Code: 530 Error text: null
> 2013-08-30 16:13:29,166 DEBUG [cloud.api.ApiServlet] (catalina-exec-25:null) ===START===
 10.215.2.19 -- GET  command=queryAsyncJobResult&jobId=a35c80cf-a1f4-41f6-a97a-9dcb97776f4c&response=json&sessionkey=iN1%2BFv5iLGYuxcPQU06GRgdBcU0%3D&_=1377904791731
> 2013-08-30 16:13:29,178 DEBUG [cloud.async.AsyncJobManagerImpl] (catalina-exec-25:null)
Async job-108 = [ a35c80cf-a1f4-41f6-a97a-9dcb97776f4c ] completed
> 2013-08-30 16:13:29,183 DEBUG [cloud.api.ApiServlet] (catalina-exec-25:null) ===END===
 10.215.2.19 -- GET  command=queryAsyncJobResult&jobId=a35c80cf-a1f4-41f6-a97a-9dcb97776f4c&response=json&sessionkey=iN1%2BFv5iLGYuxcPQU06GRgdBcU0%3D&_=1377904791731
> 2013-08-30 16:13:34,517 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-4:null)
SeqA 9-1580: Processing Seq 9-1580:  { Cmd , MgmtId: -1, via: 9, Ver: v1, Flags: 11, [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":30,"_loadInfo":"{\n
 \"connections\": []\n}","wait":0}}] }
> 2013-08-30 16:13:34,525 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-4:null)
SeqA 9-1580: Sending Seq 9-1580:  { Ans: , MgmtId: 7471666038533, via: 9, Ver: v1, Flags:
100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
> 2013-08-30 16:13:34,975 DEBUG [cloud.server.StatsCollector] (StatsCollector-2:null) HostStatsCollector
is running...
> 2013-08-30 16:13:34,982 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-497:null)
Seq 1-1168048942: Executing request
> 2013-08-30 16:13:35,018 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-497:null)
Seq 1-1168048942: Response Received:
> 2013-08-30 16:13:35,018 DEBUG [agent.transport.Request] (StatsCollector-2:null) Seq 1-1168048942:
Received:  { Ans: , MgmtId: 7471666038533, via: 1, Ver: v1, Flags: 10, { GetHostStatsAnswer
} }
> 2013-08-30 16:13:35,055 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-499:null)
Seq 6-580518622: Executing request
> 2013-08-30 16:13:35,082 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-499:null)
Seq 6-580518622: Response Received:
> 2013-08-30 16:13:35,082 DEBUG [agent.transport.Request] (StatsCollector-2:null) Seq 6-580518622:
Received:  { Ans: , MgmtId: 7471666038533, via: 6, Ver: v1, Flags: 10, { GetHostStatsAnswer
} }
> 2013-08-30 16:13:35,098 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-93:null)
Seq 8-2005992049: Executing request
> 2013-08-30 16:13:35,117 DEBUG [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null)
Zone 1 is ready to launch secondary storage VM
> 2013-08-30 16:13:35,123 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-93:null)
Seq 8-2005992049: Response Received:
> 2013-08-30 16:13:35,123 DEBUG [agent.transport.Request] (StatsCollector-2:null) Seq 8-2005992049:
Received:  { Ans: , MgmtId: 7471666038533, via: 8, Ver: v1, Flags: 10, { GetHostStatsAnswer
} }
> 2013-08-30 16:13:35,251 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:null)
Zone 1 is ready to launch console proxy
> 2013-08-30 16:13:36,130 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null)
Found 2 routers to update status.
> 2013-08-30 16:13:36,131 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null)
Found 0 networks to update RvR status.
> 2013-08-30 16:13:36,229 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null)
Found 2 routers to update status.
> 2013-08-30 16:13:36,230 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null)
Found 0 networks to update RvR status.
> 2013-08-30 16:13:41,108 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-499:null)
Seq 6-580517890: Executing request
> 2013-08-30 16:13:41,116 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-499:null)
Seq 6-580517890: Response Received:
> 2013-08-30 16:13:41,116 DEBUG [agent.transport.Request] (DirectAgent-499:null) Seq 6-580517890:
Processing:  { Ans: , MgmtId: 7471666038533, via: 6, Ver: v1, Flags: 10, [{"com.cloud.agent.api.UnsupportedAnswer":{"result":false,"details":"Unsupported
command issued:com.cloud.agent.api.CleanupNetworkRulesCmd.  Are you sure you got the right
type of server?","wait":0}}] }
> 2013-08-30 16:13:41,410 DEBUG [host.dao.HostDaoImpl] (ClusteredAgentManager Timer:null)
Resetting hosts suitable for reconnect
> 2013-08-30 16:13:41,413 DEBUG [host.dao.HostDaoImpl] (ClusteredAgentManager Timer:null)
Completed resetting hosts suitable for reconnect
> 2013-08-30 16:13:41,413 DEBUG [host.dao.HostDaoImpl] (ClusteredAgentManager Timer:null)
Acquiring hosts for clusters already owned by this management server
> 2013-08-30 16:13:41,414 DEBUG [host.dao.HostDaoImpl] (ClusteredAgentManager Timer:null)
Completed acquiring hosts for clusters already owned by this management server
> 2013-08-30 16:13:41,415 DEBUG [host.dao.HostDaoImpl] (ClusteredAgentManager Timer:null)
Acquiring hosts for clusters not owned by any management server
> 2013-08-30 16:13:41,415 DEBUG [host.dao.HostDaoImpl] (ClusteredAgentManager Timer:null)
Completed acquiring hosts for clusters not owned by any management server
> ^C
> [root@asfmgmt management]#



--
This message was sent by Atlassian JIRA
(v6.1#6144)

Mime
View raw message