Hide Forgot
+++ This bug was initially created as a clone of Bug #1035297 +++ Description of problem: VDS error when launching a new vm or starting a excisting vm after update to 3.3.1. The error: Failed to refresh VDS , vds = 7ab1a0d7-8c72-44d1-9cb5-320c456be77d : progress, error = java.lang.NullPointerException, continuing.: java.lang.NullPointerException at org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo.proceedBalloonCheck(VdsUpdateRunTimeInfo.java:1312) [vdsbroker.jar:] at org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo.refreshVmStats(VdsUpdateRunTimeInfo.java:926) [vdsbroker.jar:] at org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo.refreshVdsRunTimeInfo(VdsUpdateRunTimeInfo.java:502) [vdsbroker.jar:] at org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo.Refresh(VdsUpdateRunTimeInfo.java:343) [vdsbroker.jar:] at org.ovirt.engine.core.vdsbroker.VdsManager.OnTimer(VdsManager.java:237) [vdsbroker.jar:] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [rt.jar:1.7.0_45] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) [rt.jar:1.7.0_45] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.7.0_45] at java.lang.reflect.Method.invoke(Method.java:606) [rt.jar:1.7.0_45] 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:] Version-Release number of selected component (if applicable): Version 3.3.1 How reproducible: Steps to Reproduce: 1.Launch a new vm (or existing one) after the update from 3.3 to 3.3.1, leave the option "Memory Balloon Device Enabled" under "Resource allocation" off 2.Start the vm and check the engine.log Actual results: Your vm won't boot or sometimes after a very long time it does Expected results: Vm should boot Additional info: Before I restarted the ovirt engine I got these errors: 013-11-27 13:01:38,604 WARN [org.ovirt.engine.core.vdsbroker.VdsManager] (DefaultQuartzScheduler_Worker-46) Failed to refresh VDS , vds = 7ab1a0d7-8c72-44d1-9cb5-320c456be77d : progress, error = java.lang.NullPointerException, continuing.: java.lang.NullPointerException 2013-11-27 13:01:41,656 WARN [org.ovirt.engine.core.vdsbroker.VdsManager] (DefaultQuartzScheduler_Worker-66) Failed to refresh VDS , vds = 7ab1a0d7-8c72-44d1-9cb5-320c456be77d : progress, error = java.lang.NullPointerException, continuing.: java.lang.NullPointerException 2013-11-27 13:01:44,729 WARN [org.ovirt.engine.core.vdsbroker.VdsManager] (DefaultQuartzScheduler_Worker-80) Failed to refresh VDS , vds = 7ab1a0d7-8c72-44d1-9cb5-320c456be77d : progress, error = java.lang.NullPointerException, continuing.: java.lang.NullPointerException 2013-11-27 13:01:47,778 WARN [org.ovirt.engine.core.vdsbroker.VdsManager] (DefaultQuartzScheduler_Worker-73) Failed to refresh VDS , vds = 7ab1a0d7-8c72-44d1-9cb5-320c456be77d : progress, error = java.lang.NullPointerException, continuing.: java.lang.NullPointerException 2013-11-27 13:01:50,845 WARN [org.ovirt.engine.core.vdsbroker.VdsManager] (DefaultQuartzScheduler_Worker-93) Failed to refresh VDS , vds = 7ab1a0d7-8c72-44d1-9cb5-320c456be77d : progress, error = java.lang.NullPointerException, continuing.: java.lang.NullPointerException 2013-11-27 13:01:53,896 WARN [org.ovirt.engine.core.vdsbroker.VdsManager] (DefaultQuartzScheduler_Worker-10) Failed to refresh VDS , vds = 7ab1a0d7-8c72-44d1-9cb5-320c456be77d : progress, error = java.lang.NullPointerException, continuing.: java.lang.NullPointerException 2013-11-27 13:01:56,930 WARN [org.ovirt.engine.core.vdsbroker.VdsManager] (DefaultQuartzScheduler_Worker-22) Failed to refresh VDS , vds = 7ab1a0d7-8c72-44d1-9cb5-320c456be77d : progress, error = java.lang.NullPointerException, continuing.: java.lang.NullPointerException 2013-11-27 13:01:59,971 WARN [org.ovirt.engine.core.vdsbroker.VdsManager] (DefaultQuartzScheduler_Worker-40) Failed to refresh VDS , vds = 7ab1a0d7-8c72-44d1-9cb5-320c456be77d : progress, error = java.lang.NullPointerException, continuing.: java.lang.NullPointerException 2013-11-27 13:02:03,026 WARN [org.ovirt.engine.core.vdsbroker.VdsManager] (DefaultQuartzScheduler_Worker-26) Failed to refresh VDS , vds = 7ab1a0d7-8c72-44d1-9cb5-320c456be77d : progress, error = java.lang.NullPointerException, continuing.: java.lang.NullPointerException 2013-11-27 13:02:06,098 WARN [org.ovirt.engine.core.vdsbroker.VdsManager] (DefaultQuartzScheduler_Worker-49) Failed to refresh VDS , vds = 7ab1a0d7-8c72-44d1-9cb5-320c456be77d : progress, error = java.lang.NullPointerException, continuing.: java.lang.NullPointerException 2013-11-27 13:02:09,148 WARN [org.ovirt.engine.core.vdsbroker.VdsManager] (DefaultQuartzScheduler_Worker-72) Failed to refresh VDS , vds = 7ab1a0d7-8c72-44d1-9cb5-320c456be77d : progress, error = java.lang.NullPointerException, continuing.: java.lang.NullPointerException 2013-11-27 13:02:12,193 WARN [org.ovirt.engine.core.vdsbroker.VdsManager] (DefaultQuartzScheduler_Worker-71) Failed to refresh VDS , vds = 7ab1a0d7-8c72-44d1-9cb5-320c456be77d : progress, error = java.lang.NullPointerException, continuing.: java.lang.NullPointerException 2013-11-27 13:02:15,247 WARN [org.ovirt.engine.core.vdsbroker.VdsManager] (DefaultQuartzScheduler_Worker-81) Failed to refresh VDS , vds = 7ab1a0d7-8c72-44d1-9cb5-320c456be77d : progress, error = java.lang.NullPointerException, continuing.: java.lang.NullPointerException 2013-11-27 13:02:18,293 WARN [org.ovirt.engine.core.vdsbroker.VdsManager] (DefaultQuartzScheduler_Worker-77) Failed to refresh VDS , vds = 7ab1a0d7-8c72-44d1-9cb5-320c456be77d : progress, error = java.lang.NullPointerException, continuing.: java.lang.NullPointerException 2013-11-27 13:02:21,373 WARN [org.ovirt.engine.core.vdsbroker.VdsManager] (DefaultQuartzScheduler_Worker-16) Failed to refresh VDS , vds = 7ab1a0d7-8c72-44d1-9cb5-320c456be77d : progress, error = java.lang.NullPointerException, continuing.: java.lang.NullPointerException 2013-11-27 13:02:24,431 WARN [org.ovirt.engine.core.vdsbroker.VdsManager] (DefaultQuartzScheduler_Worker-98) Failed to refresh VDS , vds = 7ab1a0d7-8c72-44d1-9cb5-320c456be77d : progress, error = java.lang.NullPointerException, continuing.: java.lang.NullPointerException 2013-11-27 13:02:27,480 WARN [org.ovirt.engine.core.vdsbroker.VdsManager] (DefaultQuartzScheduler_Worker-5) Failed to refresh VDS , vds = 7ab1a0d7-8c72-44d1-9cb5-320c456be77d : progress, error = java.lang.NullPointerException, continuing.: java.lang.NullPointerException 2013-11-27 13:02:30,527 WARN [org.ovirt.engine.core.vdsbroker.VdsManager] (DefaultQuartzScheduler_Worker-91) Failed to refresh VDS , vds = 7ab1a0d7-8c72-44d1-9cb5-320c456be77d : progress, error = java.lang.NullPointerException, continuing.: java.lang.NullPointerException 2013-11-27 13:02:33,560 WARN [org.ovirt.engine.core.vdsbroker.VdsManager] (DefaultQuartzScheduler_Worker-34) Failed to refresh VDS , vds = 7ab1a0d7-8c72-44d1-9cb5-320c456be77d : progress, error = java.lang.NullPointerException, continuing.: java.lang.NullPointerException 2013-11-27 13:02:36,639 WARN [org.ovirt.engine.core.vdsbroker.VdsManager] (DefaultQuartzScheduler_Worker-46) Failed to refresh VDS , vds = 7ab1a0d7-8c72-44d1-9cb5-320c456be77d : progress, error = java.lang.NullPointerException, continuing.: java.lang.NullPointerException 2013-11-27 13:02:39,674 WARN [org.ovirt.engine.core.vdsbroker.VdsManager] (DefaultQuartzScheduler_Worker-65) Failed to refresh VDS , vds = 7ab1a0d7-8c72-44d1-9cb5-320c456be77d : progress, error = java.lang.NullPointerException, continuing.: java.lang.NullPointerException 2013-11-27 13:02:42,708 WARN [org.ovirt.engine.core.vdsbroker.VdsManager] (DefaultQuartzScheduler_Worker-58) Failed to refresh VDS , vds = 7ab1a0d7-8c72-44d1-9cb5-320c456be77d : progress, error = java.lang.NullPointerException, continuing.: java.lang.NullPointerException 2013-11-27 13:02:45,763 WARN [org.ovirt.engine.core.vdsbroker.VdsManager] (DefaultQuartzScheduler_Worker-21) Failed to refresh VDS , vds = 7ab1a0d7-8c72-44d1-9cb5-320c456be77d : progress, error = java.lang.NullPointerException, continuing.: java.lang.NullPointerException 2013-11-27 13:02:48,795 WARN [org.ovirt.engine.core.vdsbroker.VdsManager] (DefaultQuartzScheduler_Worker-99) Failed to refresh VDS , vds = 7ab1a0d7-8c72-44d1-9cb5-320c456be77d : progress, error = java.lang.NullPointerException, continuing.: java.lang.NullPointerException 2013-11-27 13:02:51,904 WARN [org.ovirt.engine.core.vdsbroker.VdsManager] (DefaultQuartzScheduler_Worker-14) Failed to refresh VDS , vds = 7ab1a0d7-8c72-44d1-9cb5-320c456be77d : progress, error = java.lang.NullPointerException, continuing.: java.lang.NullPointerException 2013-11-27 13:02:54,962 WARN [org.ovirt.engine.core.vdsbroker.VdsManager] (DefaultQuartzScheduler_Worker-97) Failed to refresh VDS , vds = 7ab1a0d7-8c72-44d1-9cb5-320c456be77d : progress, error = java.lang.NullPointerException, continuing.: java.lang.NullPointerException 2013-11-27 13:02:58,008 WARN [org.ovirt.engine.core.vdsbroker.VdsManager] (DefaultQuartzScheduler_Worker-31) Failed to refresh VDS , vds = 7ab1a0d7-8c72-44d1-9cb5-320c456be77d : progress, error = java.lang.NullPointerException, continuing.: java.lang.NullPointerException 2013-11-27 13:03:01,039 WARN [org.ovirt.engine.core.vdsbroker.VdsManager] (DefaultQuartzScheduler_Worker-20) Failed to refresh VDS , vds = 7ab1a0d7-8c72-44d1-9cb5-320c456be77d : progress, error = java.lang.NullPointerException, continuing.: java.lang.NullPointerException 2013-11-27 13:03:04,088 WARN [org.ovirt.engine.core.vdsbroker.VdsManager] (DefaultQuartzScheduler_Worker-88) Failed to refresh VDS , vds = 7ab1a0d7-8c72-44d1-9cb5-320c456be77d : progress, error = java.lang.NullPointerException, continuing.: java.lang.NullPointerException 2013-11-27 13:03:07,142 WARN [org.ovirt.engine.core.vdsbroker.VdsManager] (DefaultQuartzScheduler_Worker-72) Failed to refresh VDS , vds = 7ab1a0d7-8c72-44d1-9cb5-320c456be77d : progress, error = java.lang.NullPointerException, continuing.: java.lang.NullPointerException 2013-11-27 13:03:10,196 WARN [org.ovirt.engine.core.vdsbroker.VdsManager] (DefaultQuartzScheduler_Worker-59) Failed to refresh VDS , vds = 7ab1a0d7-8c72-44d1-9cb5-320c456be77d : progress, error = java.lang.NullPointerException, continuing.: java.lang.NullPointerException 2013-11-27 13:03:13,261 WARN [org.ovirt.engine.core.vdsbroker.VdsManager] (DefaultQuartzScheduler_Worker-74) Failed to refresh VDS , vds = 7ab1a0d7-8c72-44d1-9cb5-320c456be77d : progress, error = java.lang.NullPointerException, continuing.: java.lang.NullPointerException 2013-11-27 13:03:16,315 WARN [org.ovirt.engine.core.vdsbroker.VdsManager] (DefaultQuartzScheduler_Worker-75) Failed to refresh VDS , vds = 7ab1a0d7-8c72-44d1-9cb5-320c456be77d : progress, error = java.lang.NullPointerException, continuing.: java.lang.NullPointerException 2013-11-27 13:03:16,859 INFO [org.ovirt.engine.core.bll.StopVmCommand] (pool-6-thread-46) [439226bc] Running command: StopVmCommand internal: false. Entities affected : ID: 2bde28eb-2dad-4f70-8afb-ff7920484e72 Type: VM 2013-11-27 13:03:16,895 INFO [org.ovirt.engine.core.vdsbroker.DestroyVmVDSCommand] (pool-6-thread-46) [439226bc] START, DestroyVmVDSCommand(HostName = progress, HostId = 7ab1a0d7-8c72-44d1-9cb5-320c456be77d, vmId=2bde28eb-2dad-4f70-8afb-ff7920484e72, force=false, secondsToWait=0, gracefully=false), log id: 2f07a3ad 2013-11-27 13:03:16,922 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.DestroyVDSCommand] (pool-6-thread-46) [439226bc] START, DestroyVDSCommand(HostName = progress, HostId = 7ab1a0d7-8c72-44d1-9cb5-320c456be77d, vmId=2bde28eb-2dad-4f70-8afb-ff7920484e72, force=false, secondsToWait=0, gracefully=false), log id: 20baf633 2013-11-27 13:03:17,612 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.DestroyVDSCommand] (pool-6-thread-46) [439226bc] FINISH, DestroyVDSCommand, log id: 20baf633 2013-11-27 13:03:17,619 INFO [org.ovirt.engine.core.vdsbroker.DestroyVmVDSCommand] (pool-6-thread-46) [439226bc] FINISH, DestroyVmVDSCommand, return: Down, log id: 2f07a3ad 2013-11-27 13:03:17,623 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (pool-6-thread-46) [439226bc] Correlation ID: 439226bc, Job ID: de21db84-39dd-433f-b1d1-aec7f53279c1, Call Stack: null, Custom Event ID: -1, Message: VM KETTLE powered off by admin@internal (Host: progress). 2013-11-27 13:03:40,585 INFO [org.ovirt.engine.core.bll.RunVmCommand] (ajp--127.0.0.1-8702-1) [14a63e9e] Lock Acquired to object EngineLock [exclusiveLocks= key: 4b583008-772d-4df3-9612-aa0c70b78e2e value: VM , sharedLocks= ] 2013-11-27 13:03:40,593 INFO [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] (ajp--127.0.0.1-8702-1) [14a63e9e] START, IsVmDuringInitiatingVDSCommand( vmId = 4b583008-772d-4df3-9612-aa0c70b78e2e), log id: 77ed468e 2013-11-27 13:03:40,594 INFO [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] (ajp--127.0.0.1-8702-1) [14a63e9e] FINISH, IsVmDuringInitiatingVDSCommand, return: false, log id: 77ed468e 2013-11-27 13:03:40,835 INFO [org.ovirt.engine.core.bll.RunVmCommand] (pool-6-thread-46) [14a63e9e] Running command: RunVmCommand internal: false. Entities affected : ID: 4b583008-772d-4df3-9612-aa0c70b78e2e Type: VM 2013-11-27 13:03:40,970 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.IsoPrefixVDSCommand] (pool-6-thread-46) [14a63e9e] START, IsoPrefixVDSCommand(HostName = Vostok, HostId = 2a8b1829-2235-44db-be12-ac71dc6777f8, storagePoolId=5849b030-626e-47cb-ad90-3ce782d831b3), log id: 3f2e199f 2013-11-27 13:03:40,973 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.IsoPrefixVDSCommand] (pool-6-thread-46) [14a63e9e] FINISH, IsoPrefixVDSCommand, return: /rhev/data-center/mnt/vega.brusselsairport.aero:_var_lib_exports_iso/50cf24a4-d1ef-4105-a9a5-b81d91339175/images/11111111-1111-1111-1111-111111111111, log id: 3f2e199f 2013-11-27 13:03:40,995 INFO [org.ovirt.engine.core.vdsbroker.CreateVmVDSCommand] (pool-6-thread-46) [14a63e9e] START, CreateVmVDSCommand(HostName = Vostok, HostId = 2a8b1829-2235-44db-be12-ac71dc6777f8, vmId=4b583008-772d-4df3-9612-aa0c70b78e2e, vm=VM [TestRPMCreations]), log id: 24464ed2 2013-11-27 13:03:41,017 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand] (pool-6-thread-46) [14a63e9e] START, CreateVDSCommand(HostName = Vostok, HostId = 2a8b1829-2235-44db-be12-ac71dc6777f8, vmId=4b583008-772d-4df3-9612-aa0c70b78e2e, vm=VM [TestRPMCreations]), log id: 6a60d993 2013-11-27 13:03:41,055 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand] (pool-6-thread-46) [14a63e9e] org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand spiceSslCipherSuite=DEFAULT,memSize=1024,kvmEnable=true,smp=1,vmType=kvm,emulatedMachine=rhel6.4.0,keyboardLayout=fr-be,memGuaranteedSize=1024,pitReinjection=false,nice=0,display=qxl,smartcardEnable=false,smpCoresPerSocket=1,spiceSecureChannels=smain,sinputs,scursor,splayback,srecord,sdisplay,susbredir,ssmartcard,timeOffset=0,transparentHugePages=true,vmId=4b583008-772d-4df3-9612-aa0c70b78e2e,devices=[Ljava.util.HashMap;@5b4522a2,acpiEnable=true,vmName=TestRPMCreations,cpuType=Westmere,custom={} 2013-11-27 13:03:41,063 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand] (pool-6-thread-46) [14a63e9e] FINISH, CreateVDSCommand, log id: 6a60d993 2013-11-27 13:03:41,067 INFO [org.ovirt.engine.core.vdsbroker.CreateVmVDSCommand] (pool-6-thread-46) [14a63e9e] FINISH, CreateVmVDSCommand, return: WaitForLaunch, log id: 24464ed2 2013-11-27 13:03:41,070 INFO [org.ovirt.engine.core.bll.RunVmCommand] (pool-6-thread-46) [14a63e9e] Lock freed to object EngineLock [exclusiveLocks= key: 4b583008-772d-4df3-9612-aa0c70b78e2e value: VM , sharedLocks= ] 2013-11-27 13:03:41,075 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (pool-6-thread-46) [14a63e9e] Correlation ID: 14a63e9e, Job ID: 0422b9d6-8ce3-4558-98a3-6d8e64ee7c99, Call Stack: null, Custom Event ID: -1, Message: VM TestRPMCreations was started by admin@internal (Host: Vostok). 2013-11-27 13:03:41,567 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.FullListVdsCommand] (DefaultQuartzScheduler_Worker-33) START, FullListVdsCommand(HostName = Vostok, HostId = 2a8b1829-2235-44db-be12-ac71dc6777f8, vds=Host[Vostok], vmIds=[4b583008-772d-4df3-9612-aa0c70b78e2e]), log id: 2baf0b8e 2013-11-27 13:03:41,575 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.FullListVdsCommand] (DefaultQuartzScheduler_Worker-33) FINISH, FullListVdsCommand, return: [Ljava.util.HashMap;@711fae09, log id: 2baf0b8e 2013-11-27 13:03:44,718 WARN [org.ovirt.engine.core.vdsbroker.VdsManager] (DefaultQuartzScheduler_Worker-48) Failed to refresh VDS , vds = 2a8b1829-2235-44db-be12-ac71dc6777f8 : Vostok, error = java.lang.NullPointerException, continuing.: java.lang.NullPointerException 2013-11-27 13:03:47,765 WARN [org.ovirt.engine.core.vdsbroker.VdsManager] (DefaultQuartzScheduler_Worker-93) Failed to refresh VDS , vds = 2a8b1829-2235-44db-be12-ac71dc6777f8 : Vostok, error = java.lang.NullPointerException, continuing.: java.lang.NullPointerException 2013-11-27 13:03:50,815 WARN [org.ovirt.engine.core.vdsbroker.VdsManager] (DefaultQuartzScheduler_Worker-96) Failed to refresh VDS , vds = 2a8b1829-2235-44db-be12-ac71dc6777f8 : Vostok, error = java.lang.NullPointerException, continuing.: java.lang.NullPointerException --- Additional comment from Dan Kenigsberg on 2013-11-27 08:46:55 EST --- If (unlike me) you believe that this is a Vdsm bug, please report vdsm version and supply vdsm.log (look for vmCreate and hence). Would you copy the output of `vdsClient -s 0 getAllVmStsat` from the host? I'd like to see what confuses Engine. Whatever Vdsm reports, Engine should not get itself into java.lang.NullPointerException. --- Additional comment from Martin Sivák on 2013-11-27 08:53:34 EST --- Please see Dan's comments. The vdsm version, logs and Vm stats are important for debugging the engine crash as well. --- Additional comment from Koen on 2013-11-27 08:56:37 EST ---
Included in 3.3.2 beta
Closing - RHEV 3.3 Released