Details
Trivial Description
when use barematel to create instance,the instance Automatic finish OS Installation and restart the system normally,but stop or reinstall OS get problem 。
Following is the log snippet:
=========================================================
2, accountId: 2, instanceType: VirtualMachine, instanceId: 7, cmd: org.apache.cloudstack.api.command.admin.vm.StopVMCmdByAdmin, cmdInfo:
{"response":"json","id":"51c44437-b22d-4cde-ac32-b7ee5ea96521","sessionkey":"qpV/kzaFZJjyjLW0IdAh8B4jpF4\u003d","ctxDetails":"
{\"com.cloud.vm.VirtualMachine\": \"51c44437-b22d-4cde-ac32-b7ee5ea96521\"}","cmdEventType":"VM.STOP","ctxUserId":"2","httpmethod":"GET","_":"1417678580312","uuid":"51c44437-b22d-4cde-ac32-
b7ee5ea96521","ctxAccountId":"2","ctxStartEventId":"150","forced":"false"}, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null,
b22d-4cde-ac32-b7ee5ea96521&forced=false&response=json&sessionkey=qpV%2FkzaFZJjyjLW0IdAh8B4jpF4%3D&_=1417678580312
instanceType: VirtualMachine, instanceId: 7, cmd: org.apache.cloudstack.api.command.admin.vm.StopVMCmdByAdmin, cmdInfo: {"response":"json","id":"51c44437-b22d-4cde-
ac32-b7ee5ea96521","sessionkey":"qpV/kzaFZJjyjLW0IdAh8B4jpF4\u003d","ctxDetails":"
{\"com.cloud.vm.VirtualMachine\":\"51c44437-b22d-4cde-ac32- b7ee5ea96521\"}","cmdEventType":"VM.STOP","ctxUserId":"2","httpmethod":"GET","_":"1417678580312","uuid":"51c44437-b22d-4cde-ac32-
b7ee5ea96521","ctxAccountId":"2","ctxStartEventId":"150","forced":"false"}, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null,
initMsid: 345051498404, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
2014-12-04 15:36:11,026 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-41:ctx-54077a56 job-73 ctx-045d0389) Sync job-74 execution on object VmWorkJobQueue.7
2014-12-04 15:36:11,030 WARN [c.c.u.d.Merovingian2] (API-Job-Executor-41:ctx-54077a56 job-73 ctx-045d0389) Was unable to find lock for the key vm_instance7 and thread
instanceType: null, instanceId: null, cmd: com.cloud.vm.VmWorkStop,
resultCode: 0, result: null, initMsid: 345051498404, completeMsid: null, lastUpdated: null, lastPolled: null, created: Thu Dec 04 15:36:11 CST 2014}
2014-12-04 15:36:11,552 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-29:ctx-261b052e job-73/job-74) Run VM work job: com.cloud.vm.VmWorkStop for VM 7, job
com.cloud.vm.VmWorkStop
{"cleanup":false,"userId":2,"accountId":2,"vmId":7,"handlerName":"VirtualMachineManagerImpl"}2014-12-04 15:36:11,563 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-29:ctx-261b052e job-73/job-74 ctx-a631e9b0) VM state transitted from :Running to Stopping
with event: StopRequestedvm's original host id: 7 new host id: 7 host id before state transition: 7
2014-12-04 15:36:11,568 DEBUG [c.c.a.t.Request] (Work-Job-Executor-29:ctx-261b052e job-73/job-74 ctx-a631e9b0) Seq 7-3745306040111988838: Sending { Cmd , MgmtId:
345051498404, via: 7(192.168.100.24), Ver: v1, Flags: 100011, [{"com.cloud.agent.api.StopCommand":
{"isProxy":false,"executeInSequence":false,"checkBeforeCleanup":false,"vmName":"i-2-7-VM","wait":0}}] }
2014-12-04 15:36:11,568 DEBUG [c.c.a.t.Request] (Work-Job-Executor-29:ctx-261b052e job-73/job-74 ctx-a631e9b0) Seq 7-3745306040111988838: Executing: { Cmd , MgmtId:
345051498404, via: 7(192.168.100.24), Ver: v1, Flags: 100011, [{"com.cloud.agent.api.StopCommand":
{"isProxy":false,"executeInSequence":false,"checkBeforeCleanup":false,"vmName":"i-2-7-VM","wait":0}}] }
2014-12-04 15:36:11,568 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-4:ctx-e14edce9) Seq 7-3745306040111988838: Executing request
2014-12-04 15:36:11,569 DEBUG [c.c.b.n.BareMetalResourceBase] (DirectAgent-4:ctx-e14edce9) Executing: /usr/bin/python /usr/share/cloudstack-common/scripts/util/ipmi.py
power interface=default hostname=192.168.100.24 usrname=root ****** action=soft
2014-12-04 15:36:11,674 DEBUG [c.c.b.n.BareMetalResourceBase] (DirectAgent-4:ctx-e14edce9) Exit value is 1
2014-12-04 15:36:11,675 DEBUG [c.c.b.n.BareMetalResourceBase] (DirectAgent-4:ctx-e14edce9) Traceback (most recent call last): File "/usr/share/cloudstack-
common/scripts/util/ipmi.py", line 212, in <module> sys.exit(dispatch(sys.argv)) File "/usr/share/cloudstack-common/scripts/util/ipmi.py", line 204, in dispatch
return func(func_params) File "/usr/share/cloudstack-common/scripts/util/ipmi.py", line 160, in power o = ipmitool("H", hostname,"-I", lanplus, "-U", usrname, "
P", password, "chassis", "power", action)NameError: global name 'lanplus' is not defined
2014-12-04 15:36:11,675 WARN [c.c.b.n.BareMetalResourceBase] (DirectAgent-4:ctx-e14edce9) IPMI Scirpt failed due to Traceback (most recent call last): File
"/usr/share/cloudstack-common/scripts/util/ipmi.py", line 212, in <module> sys.exit(dispatch(sys.argv)) File "/usr/share/cloudstack-common/scripts/util/ipmi.py",
line 204, in dispatch return func(func_params) File "/usr/share/cloudstack-common/scripts/util/ipmi.py", line 160, in power o = ipmitool("-H", hostname,"-I",
lanplus, "U", usrname, "-P", password, "chassis", "power", action)NameError: global name 'lanplus' is not defined(/usr/bin/python /usr/share/cloudstack
common/scripts/util/ipmi.py power interface=default hostname=192.168.100.24 usrname=root ****** action=soft )
2014-12-04 15:36:11,676 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-4:ctx-e14edce9) Seq 7-3745306040111988838: Response Received:
2014-12-04 15:36:11,676 DEBUG [c.c.a.t.Request] (DirectAgent-4:ctx-e14edce9) Seq 7-3745306040111988838: Processing: { Ans: , MgmtId: 345051498404, via: 7, Ver: v1,
Flags: 10, [{"com.cloud.agent.api.StopAnswer":{"result":false,"details":"IPMI power off failed","wait":0}}] }
2014-12-04 15:36:11,676 DEBUG [c.c.a.t.Request] (Work-Job-Executor-29:ctx-261b052e job-73/job-74 ctx-a631e9b0) Seq 7-3745306040111988838: Received: { Ans: , MgmtId:
345051498404, via: 7, Ver: v1, Flags: 10,
{ StopAnswer } }
2014-12-04 15:36:11,676 WARN [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-29:ctx-261b052e job-73/job-74 ctx-a631e9b0) Unable to stop vm VM
2014-12-04 15:36:11,681 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-29:ctx-261b052e job-73/job-74 ctx-a631e9b0) VM state transitted from :Stopping to Running
with event: OperationFailedvm's original host id: 7 new host id: 7 host id before state transition: 7
2014-12-04 15:36:11,682 ERROR [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-29:ctx-261b052e job-73/job-74 ctx-a631e9b0) Invocation exception, caused by:
com.cloud.utils.exception.CloudRuntimeException: Unable to stop VM
resultCode: 0, result: null, initMsid: 345051498404, completeMsid: null, lastUpdated: null, lastPolled: null, created: Thu Dec 04 15:36:11 CST 2014}, job origin:73
com.cloud.utils.exception.CloudRuntimeException: Unable to stop VM
at com.cloud.vm.VirtualMachineManagerImpl.advanceStop(VirtualMachineManagerImpl.java:1539)
at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStop(VirtualMachineManagerImpl.java:1393)
at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStop(VirtualMachineManagerImpl.java:5206)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:107)
at com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManagerImpl.java:5340)
at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:102)
at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:503)
at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:460)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
org.apache.cloudstack.api.command.admin.vm.StopVMCmdByAdmin
java.lang.RuntimeException: Job failed due to exception Unable to stop VM
at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:114)
at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:503)
at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:460)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)