Bug 1576766
| Summary: | Deactivating host failed on ProcessOvfUpdateForStoragePoolCommand -Internal Engine Error with NPE exception - [ProcessOvfUpdateForStoragePoolCommand] (default task-41) [4fd366b9] Exception: java.lang.NullPointerException | ||||||
|---|---|---|---|---|---|---|---|
| Product: | [oVirt] ovirt-engine | Reporter: | Avihai <aefrat> | ||||
| Component: | BLL.Storage | Assignee: | Allon Mureinik <amureini> | ||||
| Status: | CLOSED DUPLICATE | QA Contact: | Elad <ebenahar> | ||||
| Severity: | high | Docs Contact: | |||||
| Priority: | unspecified | ||||||
| Version: | 4.2.3.5 | CC: | bugs | ||||
| Target Milestone: | --- | Keywords: | Automation | ||||
| Target Release: | --- | ||||||
| Hardware: | Unspecified | ||||||
| OS: | Unspecified | ||||||
| Whiteboard: | |||||||
| Fixed In Version: | Doc Type: | If docs needed, set a value | |||||
| Doc Text: | Story Points: | --- | |||||
| Clone Of: | Environment: | ||||||
| Last Closed: | 2018-05-10 11:36:49 UTC | Type: | Bug | ||||
| Regression: | --- | Mount Type: | --- | ||||
| Documentation: | --- | CRM: | |||||
| Verified Versions: | Category: | --- | |||||
| oVirt Team: | Storage | RHEL 7.3 requirements from Atomic Host: | |||||
| Cloudforms Team: | --- | Target Upstream Version: | |||||
| Embargoed: | |||||||
| Attachments: |
|
||||||
*** This bug has been marked as a duplicate of bug 1575996 *** |
Created attachment 1434321 [details] engine log Description of problem: During automation Tier2 run on hosted engine environment, reaching storage connection's TP we detach & remove all ISCSI storage domains in order to remove all ISCSI connections before starting all tests. When we tried to deactivate SD 'iscsi_2' operation failed with the following Errors & Exception: From Engine log you can see 'syncAction_daa1a241-9' showing what occured: 2018-05-05 14:46:17,020+03 INFO [org.ovirt.engine.core.bll.storage.domain.DeactivateStorageDomainWithOvfUpdateCommand] (default task-41) [storagedomains_syncAction_daa1a241-9] Lock Acquired to object 'EngineLoc k:{exclusiveLocks='[ede0cd00-aeba-40c6-9ffc-e4d469ca1d5b=STORAGE]', sharedLocks='[d1d01ef4-4f0c-11e8-a408-00163e7be007=POOL]'}' 2018-05-05 14:46:17,128+03 INFO [org.ovirt.engine.core.bll.storage.domain.DeactivateStorageDomainWithOvfUpdateCommand] (default task-41) [storagedomains_syncAction_daa1a241-9] Running command: DeactivateStorage DomainWithOvfUpdateCommand internal: false. Entities affected : ID: ede0cd00-aeba-40c6-9ffc-e4d469ca1d5b Type: StorageAction group MANIPULATE_STORAGE_DOMAIN with role type ADMIN 2018-05-05 14:46:17,189+03 INFO [org.ovirt.engine.core.bll.storage.domain.UpdateOvfStoreForStorageDomainCommand] (default task-41) [storagedomains_syncAction_daa1a241-9] Running command: UpdateOvfStoreForStorag eDomainCommand internal: true. Entities affected : ID: ede0cd00-aeba-40c6-9ffc-e4d469ca1d5b Type: StorageAction group MANIPULATE_STORAGE_DOMAIN with role type ADMIN 2018-05-05 14:46:17,198+03 INFO [org.ovirt.engine.core.bll.storage.ovfstore.ProcessOvfUpdateForStoragePoolCommand] (default task-41) [4fd366b9] Running command: ProcessOvfUpdateForStoragePoolCommand internal: t rue. Entities affected : ID: d1d01ef4-4f0c-11e8-a408-00163e7be007 Type: StoragePool 2018-05-05 14:46:17,210+03 INFO [org.ovirt.engine.core.bll.storage.ovfstore.ProcessOvfUpdateForStoragePoolCommand] (default task-41) [4fd366b9] Attempting to update VM OVFs in Data Center 'golden_env_mixed' 2018-05-05 14:46:17,350+03 WARN [org.ovirt.engine.core.vdsbroker.builder.vminfo.VmInfoBuildUtils] (default task-41) [4fd366b9] No host NUMA nodes found for vm HostedEngine (1d7f6b2b-3657-4780-8275-b249e63a5a81) 2018-05-05 14:46:17,357+03 ERROR [org.ovirt.engine.core.bll.storage.ovfstore.ProcessOvfUpdateForStoragePoolCommand] (default task-41) [4fd366b9] Command 'org.ovirt.engine.core.bll.storage.ovfstore.ProcessOvfUpda teForStoragePoolCommand' failed: null 2018-05-05 14:46:17,357+03 ERROR [org.ovirt.engine.core.bll.storage.ovfstore.ProcessOvfUpdateForStoragePoolCommand] (default task-41) [4fd366b9] Exception: java.lang.NullPointerException at org.ovirt.engine.core.vdsbroker.builder.vminfo.LibvirtVmXmlBuilder.writeInterface(LibvirtVmXmlBuilder.java:2045) [vdsbroker.jar:] at org.ovirt.engine.core.vdsbroker.builder.vminfo.LibvirtVmXmlBuilder.lambda$writeInterfaces$24(LibvirtVmXmlBuilder.java:1096) [vdsbroker.jar:] at java.util.stream.ForEachOps$ForEachOp$OfRef.accept(ForEachOps.java:184) [rt.jar:1.8.0_171] at java.util.stream.SortedOps$SizedRefSortingSink.end(SortedOps.java:352) [rt.jar:1.8.0_171] at java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:482) [rt.jar:1.8.0_171] at java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:471) [rt.jar:1.8.0_171] at java.util.stream.ForEachOps$ForEachOp.evaluateSequential(ForEachOps.java:151) [rt.jar:1.8.0_171] at java.util.stream.ForEachOps$ForEachOp$OfRef.evaluateSequential(ForEachOps.java:174) [rt.jar:1.8.0_171] at java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234) [rt.jar:1.8.0_171] …………………………………………………………………………………………….. …………………………………………………………………………………………….. …………………………………………………………………………………………….. at io.undertow.servlet.handlers.ServletInitialHandler$1.handleRequest(ServletInitialHandler.java:104) at io.undertow.server.Connectors.executeRootHandler(Connectors.java:330) at io.undertow.server.HttpServerExchange$1.run(HttpServerExchange.java:812) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [rt.jar:1.8.0_171] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [rt.jar:1.8.0_171] at java.lang.Thread.run(Thread.java:748) [rt.jar:1.8.0_171] 2018-05-05 14:46:17,385+03 INFO [org.ovirt.engine.core.bll.storage.ovfstore.ProcessOvfUpdateForStoragePoolCommand] (default task-41) [4fd366b9] Lock freed to object 'EngineLock:{exclusiveLocks='[ede0cd00-aeba-4 0c6-9ffc-e4d469ca1d5b=STORAGE]', sharedLocks='[d1d01ef4-4f0c-11e8-a408-00163e7be007=POOL]'}' 2018-05-05 14:46:17,442+03 INFO [org.ovirt.engine.core.bll.CommandCompensator] (default task-41) [storagedomains_syncAction_daa1a241-9] Command [id=d2104976-7be0-4a34-a1f8-3dacb6b8e7e8]: Compensating CHANGED_ST ATUS_ONLY of org.ovirt.engine.core.common.businessentities.StoragePoolIsoMap; snapshot: EntityStatusSnapshot:{id='StoragePoolIsoMapId:{storagePoolId='d1d01ef4-4f0c-11e8-a408-00163e7be007', storageId='ede0cd00-ae ba-40c6-9ffc-e4d469ca1d5b'}', status='Unknown'}. 2018-05-05 14:46:17,463+03 WARN [org.ovirt.engine.core.bll.lock.InMemoryLockManager] (default task-41) [storagedomains_syncAction_daa1a241-9] Trying to release a shared lock for key: 'd1d01ef4-4f0c-11e8-a408-00163e7be007POOL' , but lock does not exist 2018-05-05 14:46:17,463+03 WARN [org.ovirt.engine.core.bll.lock.InMemoryLockManager] (default task-41) [storagedomains_syncAction_daa1a241-9] Trying to release exclusive lock which does not exist, lock key: 'ede0cd00-aeba-40c6-9ffc-e4d469ca1d5bSTORAGE' 2018-05-05 14:46:17,463+03 INFO [org.ovirt.engine.core.bll.storage.domain.DeactivateStorageDomainWithOvfUpdateCommand] (default task-41) [storagedomains_syncAction_daa1a241-9] Lock freed to object 'EngineLock:{exclusiveLocks='[ede0cd00-aeba-40c6-9ffc-e4d469ca1d5b=STORAGE]', sharedLocks='[d1d01ef4-4f0c-11e8-a408-00163e7be007=POOL]'}' 2018-05-05 14:46:17,464+03 ERROR [org.ovirt.engine.api.restapi.resource.AbstractBackendResource] (default task-41) [] Operation Failed: [Internal Engine Error] 2018-05-05 14:46:17,574+03 INFO [org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCallback] (EE-ManagedThreadFactory-engineScheduled-Thread-79) [storagedomains_syncAction_daa1a241-9] Command 'DeactivateStorageDomainWithOvfUpdate' id: 'd2104976-7be0-4a34-a1f8-3dacb6b8e7e8' child commands '[109ea62e-7cd1-4924-a106-55a04e221651]' executions were completed, status 'FAILED' 2018-05-05 14:46:18,593+03 ERROR [org.ovirt.engine.core.bll.storage.domain.DeactivateStorageDomainWithOvfUpdateCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-77) [storagedomains_syncAction_daa1a241-9] Ending command 'org.ovirt.engine.core.bll.storage.domain.DeactivateStorageDomainWithOvfUpdateCommand' with failure. 2018-05-05 14:46:18,605+03 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedThreadFactory-engineScheduled-Thread-77) [storagedomains_syncAction_daa1a241-9] EVENT_ID: USER_DEACTIVATE_STORAGE_DOMAIN_FAILED(969), Failed to deactivate Storage Domain iscsi_2 (Data Center golden_env_mixed). 2018-05-05 14:46:18,608+03 WARN [org.ovirt.engine.core.bll.lock.InMemoryLockManager] (EE-ManagedThreadFactory-engineScheduled-Thread-77) [storagedomains_syncAction_daa1a241-9] Trying to release a shared lock for key: 'd1d01ef4-4f0c-11e8-a408-00163e7be007POOL' , but lock does not exist 2018-05-05 14:46:18,608+03 WARN [org.ovirt.engine.core.bll.lock.InMemoryLockManager] (EE-ManagedThreadFactory-engineScheduled-Thread-77) [storagedomains_syncAction_daa1a241-9] Trying to release exclusive lock which does not exist, lock key: 'ede0cd00-aeba-40c6-9ffc-e4d469ca1d5bSTORAGE' 2018-05-05 14:46:18,608+03 INFO [org.ovirt.engine.core.bll.storage.domain.DeactivateStorageDomainWithOvfUpdateCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-77) [storagedomains_syncAction_daa1a241-9] Lock freed to object 'EngineLock:{exclusiveLocks='[ede0cd00-aeba-40c6-9ffc-e4d469ca1d5b=STORAGE]', sharedLocks='[d1d01ef4-4f0c-11e8-a408-00163e7be007=POOL]'}' Version-Release number of selected component (if applicable): ovirt-engine-4.2.3.4-0.1.el7.noarch vdsm-4.20.27.1-1.el7ev.x86_64 How reproducible: Happened once on a during Tier2 Starting storage connections TP. Steps to Reproduce: Not straightforward, Tier2 ran a lot of prior tests that could have caused this issue. the final trigger to this issue was deactivating iscsi_2 storage domain. Issue occurred in the Setup phase of storage connection TP that deactivate's & removes all ISCSI SD's (iscsi_0,iscsi_1,iscsi_2) Actual results: Deactivation failed with Internal Engine Error and NPE exception - [ProcessOvfUpdateForStoragePoolCommand] (default task-41) [4fd366b9] Exception: java.lang.NullPointerException Expected results: Additional info: