Attachment 943327 Details for Bug 1148714 – cannot run VM part of engine.log

cannot run VM part of engine.log

relevant2-engine.log (text/plain), 15.25 KB, created by Antonin Pagac on 2014-10-02 08:32:21 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Antonin Pagac

Created: 2014-10-02 08:32:21 UTC

Size: 15.25 KB

patch

obsolete

>2014-10-02 10:23:41,789 INFO  [org.ovirt.engine.core.bll.RunVmCommand] (ajp-/127.0.0.1:8702-7) [6115fdf1] Lock Acquired to object EngineLock [exclusiveLocks= key: 51838b3d-8f68-44c0-8db3-491e81ec8b11 value: VM
>, sharedLocks= ]
>2014-10-02 10:23:41,848 INFO  [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] (ajp-/127.0.0.1:8702-7) [6115fdf1] START, IsVmDuringInitiatingVDSCommand( vmId = 51838b3d-8f68-44c0-8db3-491e81ec8b11), log id: 2b00efa8
>2014-10-02 10:23:41,849 INFO  [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] (ajp-/127.0.0.1:8702-7) [6115fdf1] FINISH, IsVmDuringInitiatingVDSCommand, return: false, log id: 2b00efa8
>2014-10-02 10:23:41,996 INFO  [org.ovirt.engine.core.bll.RunVmCommand] (org.ovirt.thread.pool-7-thread-46) [6115fdf1] Running command: RunVmCommand internal: false. Entities affected :  ID: 51838b3d-8f68-44c0-8db3-491e81ec8b11 Type: VMAction group VM_BASIC_OPERATIONS with role type USER
>2014-10-02 10:23:42,088 INFO  [org.ovirt.engine.core.vdsbroker.UpdateVmDynamicDataVDSCommand] (org.ovirt.thread.pool-7-thread-46) [6115fdf1] START, UpdateVmDynamicDataVDSCommand(HostName = Host1, HostId = a2067a87-b188-4ec8-b715-a10175741ec0, vmDynamic=org.ovirt.engine.core.common.businessentities.VmDynamic@ddc27dfb), log id: 3e2332a4
>2014-10-02 10:23:42,092 INFO  [org.ovirt.engine.core.vdsbroker.UpdateVmDynamicDataVDSCommand] (org.ovirt.thread.pool-7-thread-46) [6115fdf1] FINISH, UpdateVmDynamicDataVDSCommand, log id: 3e2332a4
>2014-10-02 10:23:42,109 INFO  [org.ovirt.engine.core.vdsbroker.CreateVmVDSCommand] (org.ovirt.thread.pool-7-thread-46) [6115fdf1] START, CreateVmVDSCommand(HostName = Host1, HostId = a2067a87-b188-4ec8-b715-a10175741ec0, vmId=51838b3d-8f68-44c0-8db3-491e81ec8b11, vm=VM [fed20]), log id: 3e0c46c5
>2014-10-02 10:23:42,124 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand] (org.ovirt.thread.pool-7-thread-46) [6115fdf1] START, CreateVDSCommand(HostName = Host1, HostId = a2067a87-b188-4ec8-b715-a10175741ec0, vmId=51838b3d-8f68-44c0-8db3-491e81ec8b11, vm=VM [fed20]), log id: 775354e4
>2014-10-02 10:23:42,230 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand] (org.ovirt.thread.pool-7-thread-46) [6115fdf1] Failed in CreateVDS method, for vds: Host1; host: slot-6.rhev.lab.eng.brq.redhat.com
>2014-10-02 10:23:42,231 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand] (org.ovirt.thread.pool-7-thread-46) [6115fdf1] Command CreateVDSCommand(HostName = Host1, HostId = a2067a87-b188-4ec8-b715-a10175741ec0, vmId=51838b3d-8f68-44c0-8db3-491e81ec8b11, vm=VM [fed20]) execution failed. Exception: ArrayIndexOutOfBoundsException: 1
>2014-10-02 10:23:42,231 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand] (org.ovirt.thread.pool-7-thread-46) [6115fdf1] FINISH, CreateVDSCommand, log id: 775354e4
>2014-10-02 10:23:42,231 ERROR [org.ovirt.engine.core.vdsbroker.CreateVmVDSCommand] (org.ovirt.thread.pool-7-thread-46) [6115fdf1] Error in excuting CreateVmVDSCommand: java.lang.ArrayIndexOutOfBoundsException: 1
>	at org.ovirt.engine.core.dao.VdsNumaNodeDAODbFacadeImpl.getDistanceMap(VdsNumaNodeDAODbFacadeImpl.java:208) [dal.jar:]
>	at org.ovirt.engine.core.dao.VdsNumaNodeDAODbFacadeImpl.access$000(VdsNumaNodeDAODbFacadeImpl.java:20) [dal.jar:]
>	at org.ovirt.engine.core.dao.VdsNumaNodeDAODbFacadeImpl$1.mapRow(VdsNumaNodeDAODbFacadeImpl.java:184) [dal.jar:]
>	at org.ovirt.engine.core.dao.VdsNumaNodeDAODbFacadeImpl$1.mapRow(VdsNumaNodeDAODbFacadeImpl.java:168) [dal.jar:]
>	at org.springframework.jdbc.core.RowMapperResultSetExtractor.extractData(RowMapperResultSetExtractor.java:92) [spring-jdbc.jar:3.1.1.RELEASE]
>	at org.springframework.jdbc.core.RowMapperResultSetExtractor.extractData(RowMapperResultSetExtractor.java:1) [spring-jdbc.jar:3.1.1.RELEASE]
>	at org.springframework.jdbc.core.JdbcTemplate$1.doInPreparedStatement(JdbcTemplate.java:649) [spring-jdbc.jar:3.1.1.RELEASE]
>	at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:587) [spring-jdbc.jar:3.1.1.RELEASE]
>	at org.springframework.jdbc.core.JdbcTemplate.query(JdbcTemplate.java:637) [spring-jdbc.jar:3.1.1.RELEASE]
>	at org.springframework.jdbc.core.JdbcTemplate.query(JdbcTemplate.java:666) [spring-jdbc.jar:3.1.1.RELEASE]
>	at org.springframework.jdbc.core.JdbcTemplate.query(JdbcTemplate.java:706) [spring-jdbc.jar:3.1.1.RELEASE]
>	at org.ovirt.engine.core.dal.dbbroker.PostgresDbEngineDialect$PostgresSimpleJdbcCall.executeCallInternal(PostgresDbEngineDialect.java:154) [dal.jar:]
>	at org.ovirt.engine.core.dal.dbbroker.PostgresDbEngineDialect$PostgresSimpleJdbcCall.doExecute(PostgresDbEngineDialect.java:120) [dal.jar:]
>	at org.springframework.jdbc.core.simple.SimpleJdbcCall.execute(SimpleJdbcCall.java:181) [spring-jdbc.jar:3.1.1.RELEASE]
>	at org.ovirt.engine.core.dal.dbbroker.SimpleJdbcCallsHandler.executeImpl(SimpleJdbcCallsHandler.java:141) [dal.jar:]
>	at org.ovirt.engine.core.dal.dbbroker.SimpleJdbcCallsHandler.executeReadList(SimpleJdbcCallsHandler.java:103) [dal.jar:]
>	at org.ovirt.engine.core.dao.VdsNumaNodeDAODbFacadeImpl.getAllVdsNumaNodeByVdsId(VdsNumaNodeDAODbFacadeImpl.java:27) [dal.jar:]
>	at org.ovirt.engine.core.vdsbroker.vdsbroker.VmInfoBuilder.addNumaSetting(VmInfoBuilder.java:1143) [vdsbroker.jar:]
>	at org.ovirt.engine.core.vdsbroker.vdsbroker.VmInfoBuilder.buildVmNumaProperties(VmInfoBuilder.java:1128) [vdsbroker.jar:]
>	at org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand.buildVmData(CreateVDSCommand.java:82) [vdsbroker.jar:]
>	at org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand.executeVdsBrokerCommand(CreateVDSCommand.java:26) [vdsbroker.jar:]
>	at org.ovirt.engine.core.vdsbroker.vdsbroker.VdsBrokerCommand.executeVDSCommand(VdsBrokerCommand.java:96) [vdsbroker.jar:]
>	at org.ovirt.engine.core.vdsbroker.VDSCommandBase.executeCommand(VDSCommandBase.java:56) [vdsbroker.jar:]
>	at org.ovirt.engine.core.dal.VdcCommandBase.execute(VdcCommandBase.java:31) [dal.jar:]
>	at org.ovirt.engine.core.vdsbroker.CreateVmVDSCommand.executeVdsIdCommand(CreateVmVDSCommand.java:44) [vdsbroker.jar:]
>	at org.ovirt.engine.core.vdsbroker.VdsIdVDSCommandBase.executeVDSCommand(VdsIdVDSCommandBase.java:48) [vdsbroker.jar:]
>	at org.ovirt.engine.core.vdsbroker.VDSCommandBase.executeCommand(VDSCommandBase.java:56) [vdsbroker.jar:]
>	at org.ovirt.engine.core.dal.VdcCommandBase.execute(VdcCommandBase.java:31) [dal.jar:]
>	at org.ovirt.engine.core.vdsbroker.ResourceManager.runVdsCommand(ResourceManager.java:418) [vdsbroker.jar:]
>	at org.ovirt.engine.core.bll.VDSBrokerFrontendImpl.RunVdsCommand(VDSBrokerFrontendImpl.java:33) [bll.jar:]
>	at org.ovirt.engine.core.bll.VDSBrokerFrontendImpl.RunAsyncVdsCommand(VDSBrokerFrontendImpl.java:48) [bll.jar:]
>	at org.ovirt.engine.core.bll.RunVmCommand.createVm(RunVmCommand.java:507) [bll.jar:]
>	at org.ovirt.engine.core.bll.RunVmCommand.runVm(RunVmCommand.java:229) [bll.jar:]
>	at org.ovirt.engine.core.bll.RunVmCommand.perform(RunVmCommand.java:346) [bll.jar:]
>	at org.ovirt.engine.core.bll.RunVmCommand.executeVmCommand(RunVmCommand.java:274) [bll.jar:]
>	at org.ovirt.engine.core.bll.VmCommand.executeCommand(VmCommand.java:100) [bll.jar:]
>	at org.ovirt.engine.core.bll.CommandBase.executeWithoutTransaction(CommandBase.java:1168) [bll.jar:]
>	at org.ovirt.engine.core.bll.CommandBase.executeActionInTransactionScope(CommandBase.java:1307) [bll.jar:]
>	at org.ovirt.engine.core.bll.CommandBase.runInTransaction(CommandBase.java:1932) [bll.jar:]
>	at org.ovirt.engine.core.utils.transaction.TransactionSupport.executeInSuppressed(TransactionSupport.java:174) [utils.jar:]
>	at org.ovirt.engine.core.utils.transaction.TransactionSupport.executeInScope(TransactionSupport.java:116) [utils.jar:]
>	at org.ovirt.engine.core.bll.CommandBase.execute(CommandBase.java:1331) [bll.jar:]
>	at org.ovirt.engine.core.bll.CommandBase.executeAction(CommandBase.java:344) [bll.jar:]
>	at org.ovirt.engine.core.bll.MultipleActionsRunner.executeValidatedCommand(MultipleActionsRunner.java:191) [bll.jar:]
>	at org.ovirt.engine.core.bll.MultipleActionsRunner.runCommands(MultipleActionsRunner.java:158) [bll.jar:]
>	at org.ovirt.engine.core.bll.SortedMultipleActionsRunnerBase.runCommands(SortedMultipleActionsRunnerBase.java:20) [bll.jar:]
>	at org.ovirt.engine.core.bll.MultipleActionsRunner$2.run(MultipleActionsRunner.java:167) [bll.jar:]
>	at org.ovirt.engine.core.utils.threadpool.ThreadPoolUtil$InternalWrapperRunnable.run(ThreadPoolUtil.java:90) [utils.jar:]
>	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471) [rt.jar:1.7.0_65]
>	at java.util.concurrent.FutureTask.run(FutureTask.java:262) [rt.jar:1.7.0_65]
>	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) [rt.jar:1.7.0_65]
>	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) [rt.jar:1.7.0_65]
>	at java.lang.Thread.run(Thread.java:745) [rt.jar:1.7.0_65]
>
>2014-10-02 10:23:42,234 ERROR [org.ovirt.engine.core.vdsbroker.CreateVmVDSCommand] (org.ovirt.thread.pool-7-thread-46) [6115fdf1] Command CreateVmVDSCommand(HostName = Host1, HostId = a2067a87-b188-4ec8-b715-a10175741ec0, vmId=51838b3d-8f68-44c0-8db3-491e81ec8b11, vm=VM [fed20]) execution failed. Exception: RuntimeException: java.lang.ArrayIndexOutOfBoundsException: 1
>2014-10-02 10:23:42,234 INFO  [org.ovirt.engine.core.vdsbroker.CreateVmVDSCommand] (org.ovirt.thread.pool-7-thread-46) [6115fdf1] FINISH, CreateVmVDSCommand, log id: 3e0c46c5
>2014-10-02 10:23:42,234 WARN  [org.ovirt.engine.core.bll.RunVmCommand] (org.ovirt.thread.pool-7-thread-46) [6115fdf1] Failed to run VM fed20: VdcBLLException: java.lang.RuntimeException: java.lang.ArrayIndexOutOfBoundsException: 1 (Failed with error ENGINE and code 5001)
>2014-10-02 10:23:42,235 INFO  [org.ovirt.engine.core.bll.RunVmCommand] (org.ovirt.thread.pool-7-thread-46) [6115fdf1] Lock freed to object EngineLock [exclusiveLocks= key: 51838b3d-8f68-44c0-8db3-491e81ec8b11 value: VM
>, sharedLocks= ]
>2014-10-02 10:23:42,235 INFO  [org.ovirt.engine.core.bll.RunVmCommand] (org.ovirt.thread.pool-7-thread-46) [6115fdf1] Trying to rerun VM fed20
>2014-10-02 10:23:42,277 WARN  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-7-thread-46) [6115fdf1] Correlation ID: 6115fdf1, Job ID: 283f1716-ded9-42fc-adae-e8445540a851, Call Stack: null, Custom Event ID: -1, Message: Failed to run VM fed20 on Host Host1.
>2014-10-02 10:23:42,288 INFO  [org.ovirt.engine.core.bll.RunVmCommand] (org.ovirt.thread.pool-7-thread-46) [6115fdf1] Lock Acquired to object EngineLock [exclusiveLocks= key: 51838b3d-8f68-44c0-8db3-491e81ec8b11 value: VM
>, sharedLocks= ]
>2014-10-02 10:23:42,326 INFO  [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] (org.ovirt.thread.pool-7-thread-46) [6115fdf1] START, IsVmDuringInitiatingVDSCommand( vmId = 51838b3d-8f68-44c0-8db3-491e81ec8b11), log id: 37039540
>2014-10-02 10:23:42,326 INFO  [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] (org.ovirt.thread.pool-7-thread-46) [6115fdf1] FINISH, IsVmDuringInitiatingVDSCommand, return: false, log id: 37039540
>2014-10-02 10:23:42,332 WARN  [org.ovirt.engine.core.bll.RunVmCommand] (org.ovirt.thread.pool-7-thread-46) [6115fdf1] CanDoAction of action RunVm failed. Reasons:VAR__ACTION__RUN,VAR__TYPE__VM,VAR__ACTION__RUN,VAR__TYPE__VM,VAR__ACTION__RUN,VAR__TYPE__VM,SCHEDULING_NO_HOSTS
>2014-10-02 10:23:42,332 INFO  [org.ovirt.engine.core.bll.RunVmCommand] (org.ovirt.thread.pool-7-thread-46) [6115fdf1] Lock freed to object EngineLock [exclusiveLocks= key: 51838b3d-8f68-44c0-8db3-491e81ec8b11 value: VM
>, sharedLocks= ]
>2014-10-02 10:23:42,350 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-7-thread-46) [6115fdf1] Correlation ID: 6115fdf1, Job ID: 283f1716-ded9-42fc-adae-e8445540a851, Call Stack: null, Custom Event ID: -1, Message: Failed to run VM fed20 (User: admin).
>2014-10-02 10:23:42,388 INFO  [org.ovirt.engine.core.bll.ProcessDownVmCommand] (org.ovirt.thread.pool-7-thread-43) [676261d0] Running command: ProcessDownVmCommand internal: true.
>2014-10-02 10:23:56,872 ERROR [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-64) [94f10bd] ResourceManager::refreshVdsRunTimeInfo: Error: ArrayIndexOutOfBoundsException: 1, vds = a2067a87-b188-4ec8-b715-a10175741ec0 : Host1
>2014-10-02 10:23:56,872 ERROR [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-64) [94f10bd] ArrayIndexOutOfBoundsException: 1: java.lang.ArrayIndexOutOfBoundsException: 1
>	at org.ovirt.engine.core.dao.VdsNumaNodeDAODbFacadeImpl.getDistanceMap(VdsNumaNodeDAODbFacadeImpl.java:208) [dal.jar:]
>	at org.ovirt.engine.core.dao.VdsNumaNodeDAODbFacadeImpl.access$000(VdsNumaNodeDAODbFacadeImpl.java:20) [dal.jar:]
>	at org.ovirt.engine.core.dao.VdsNumaNodeDAODbFacadeImpl$1.mapRow(VdsNumaNodeDAODbFacadeImpl.java:184) [dal.jar:]
>	at org.ovirt.engine.core.dao.VdsNumaNodeDAODbFacadeImpl$1.mapRow(VdsNumaNodeDAODbFacadeImpl.java:168) [dal.jar:]
>	at org.springframework.jdbc.core.RowMapperResultSetExtractor.extractData(RowMapperResultSetExtractor.java:92) [spring-jdbc.jar:3.1.1.RELEASE]
>	at org.springframework.jdbc.core.RowMapperResultSetExtractor.extractData(RowMapperResultSetExtractor.java:1) [spring-jdbc.jar:3.1.1.RELEASE]
>	at org.springframework.jdbc.core.JdbcTemplate$1.doInPreparedStatement(JdbcTemplate.java:649) [spring-jdbc.jar:3.1.1.RELEASE]
>	at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:587) [spring-jdbc.jar:3.1.1.RELEASE]
>	at org.springframework.jdbc.core.JdbcTemplate.query(JdbcTemplate.java:637) [spring-jdbc.jar:3.1.1.RELEASE]
>	at org.springframework.jdbc.core.JdbcTemplate.query(JdbcTemplate.java:666) [spring-jdbc.jar:3.1.1.RELEASE]
>	at org.springframework.jdbc.core.JdbcTemplate.query(JdbcTemplate.java:706) [spring-jdbc.jar:3.1.1.RELEASE]
>	at org.ovirt.engine.core.dal.dbbroker.PostgresDbEngineDialect$PostgresSimpleJdbcCall.executeCallInternal(PostgresDbEngineDialect.java:154) [dal.jar:]
>	at org.ovirt.engine.core.dal.dbbroker.PostgresDbEngineDialect$PostgresSimpleJdbcCall.doExecute(PostgresDbEngineDialect.java:120) [dal.jar:]
>	at org.springframework.jdbc.core.simple.SimpleJdbcCall.execute(SimpleJdbcCall.java:181) [spring-jdbc.jar:3.1.1.RELEASE]
>	at org.ovirt.engine.core.dal.dbbroker.SimpleJdbcCallsHandler.executeImpl(SimpleJdbcCallsHandler.java:141) [dal.jar:]
>	at org.ovirt.engine.core.dal.dbbroker.SimpleJdbcCallsHandler.executeReadList(SimpleJdbcCallsHandler.java:103) [dal.jar:]
>	at org.ovirt.engine.core.dao.VdsNumaNodeDAODbFacadeImpl.getAllVdsNumaNodeByVdsId(VdsNumaNodeDAODbFacadeImpl.java:27) [dal.jar:]
>	at org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo.saveNumaStatisticsDataToDb(VdsUpdateRunTimeInfo.java:343) [vdsbroker.jar:]
>	at org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo.saveDataToDb(VdsUpdateRunTimeInfo.java:185) [vdsbroker.jar:]
>	at org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo.refresh(VdsUpdateRunTimeInfo.java:516) [vdsbroker.jar:]
>	at org.ovirt.engine.core.vdsbroker.VdsManager.onTimer(VdsManager.java:236) [vdsbroker.jar:]
>	at sun.reflect.GeneratedMethodAccessor45.invoke(Unknown Source) [:1.7.0_65]
>	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.7.0_65]
>	at java.lang.reflect.Method.invoke(Method.java:606) [rt.jar:1.7.0_65]
>	at org.ovirt.engine.core.utils.timer.JobWrapper.execute(JobWrapper.java:60) [scheduler.jar:]
>	at org.quartz.core.JobRunShell.run(JobRunShell.java:213) [quartz.jar:]
>	at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:557) [quartz.jar:]
>

Actions: View

Attachments on bug 1148714: 943322 | 943327