Bug 1600165
| Summary: | CopyData fails with NPE during failed cold move due to inaccessible storage | ||||||
|---|---|---|---|---|---|---|---|
| Product: | [oVirt] ovirt-engine | Reporter: | Kevin Alon Goldblatt <kgoldbla> | ||||
| Component: | BLL.Storage | Assignee: | Fedor Gavrilov <fgavrilo> | ||||
| Status: | CLOSED NOTABUG | QA Contact: | Shir Fishbain <sfishbai> | ||||
| Severity: | high | Docs Contact: | |||||
| Priority: | unspecified | ||||||
| Version: | 4.2.5 | CC: | aefrat, bugs, ebenahar, eshenitz, fgavrilo, mkalinin, tnisan | ||||
| Target Milestone: | ovirt-4.4.0 | Flags: | pm-rhel:
ovirt-4.4+
|
||||
| Target Release: | --- | ||||||
| Hardware: | x86_64 | ||||||
| OS: | Unspecified | ||||||
| Whiteboard: | |||||||
| Fixed In Version: | Doc Type: | If docs needed, set a value | |||||
| Doc Text: | Story Points: | --- | |||||
| Clone Of: | Environment: | ||||||
| Last Closed: | 2020-02-10 12:22:32 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: |
|
||||||
Created attachment 1458135 [details]
engine and vdsm logs
Adding logs
This bug has not been marked as blocker for oVirt 4.3.0. Since we are releasing it tomorrow, January 29th, this bug has been re-targeted to 4.3.1. |
Description of problem: A null pointer exception occurs during a failed cold move operation due to inaccessible storage Version-Release number of selected component (if applicable): ovirt-engine-4.2.5.1_SNAPSHOT-73.g63529de.0.scratch.master.el7ev.noarch vdsm-4.20.33-1.el7ev.x86_64 How reproducible: 100% Steps to Reproduce: Verified with the following scenario: --------------------------------------- 1. Start cold move of a large disk 2. After a few seconds -> block access from the host (that is running move) to the storage >>>>> the move operation fails with a null pointer exception during copydata Actual results: the move operation fails with a null pointer exception during copydata Expected results: the move operation should fail WITHOUT a null pointer exception during copydata Additional info: Vdsm.log: -------------------------------- 2018-07-11 12:34:19,120+0300 ERROR (check/loop) [storage.Monitor] Error checking path /dev/bb4af7a9-3015-4b37-8984-039da776fcb7/metadata (monitor:498) Traceback (most recent call last): File "/usr/lib/python2.7/site-packages/vdsm/storage/monitor.py", line 496, in _pathChecked delay = result.delay() File "/usr/lib/python2.7/site-packages/vdsm/storage/check.py", line 391, in delay raise exception.MiscFileReadException(self.path, self.rc, self.err) MiscFileReadException: Internal file read failure: ('/dev/bb4af7a9-3015-4b37-8984-039da776fcb7/metadata', 1, 'Read timeout') 2018-07-11 12:34:19,120+0300 INFO (check/loop) [storage.Monitor] Domain bb4af7a9-3015-4b37-8984-039da776fcb7 became INVALID (monitor:469) 2018-07-11 12:34:19,131+0300 DEBUG (event/33) [storage.Event.storage.DomainMonitor.onDomainStateChange] Emitting event (misc:432) 2018-07-11 12:34:19,132+0300 DEBUG (event/33) [storage.Event.storage.DomainMonitor.onDomainStateChange] Calling registered method `contEIOVms` (misc:442) 2018-07-11 12:34:19,133+0300 DEBUG (event/33) [storage.Event.storage.DomainMonitor.onDomainStateChange] Calling registered method `_domainStateChange` (misc:442) 2018-07-11 12:34:19,134+0300 DEBUG (event/33) [storage.Event.storage.DomainMonitor.onDomainStateChange] Event emitted (misc:451) 2018-07-11 12:34:20,352+0300 INFO (jsonrpc/2) [vdsm.api] FINISH getSpmStatus error=(-202, 'Sanlock resource read failure', 'IO timeout') from=::ffff:10.35.162.9,48586, task_id=9c3b94ea-359d-4221-838b-ae402dffe840 (api:50) 2018-07-11 12:34:20,353+0300 ERROR (jsonrpc/2) [storage.TaskManager.Task] (Task='9c3b94ea-359d-4221-838b-ae402dffe840') Unexpected error (task:875) Traceback (most recent call last): File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 882, in _run return fn(*args, **kargs) File "<string>", line 2, in getSpmStatus File "/usr/lib/python2.7/site-packages/vdsm/common/api.py", line 48, in method ret = func(*args, **kwargs) File "/usr/lib/python2.7/site-packages/vdsm/storage/hsm.py", line 636, in getSpmStatus status = self._getSpmStatusInfo(pool) File "/usr/lib/python2.7/site-packages/vdsm/storage/hsm.py", line 630, in _getSpmStatusInfo (pool.spmRole,) + pool.getSpmStatus())) File "/usr/lib/python2.7/site-packages/vdsm/storage/sp.py", line 141, in getSpmStatus return self._backend.getSpmStatus() File "/usr/lib/python2.7/site-packages/vdsm/storage/spbackends.py", line 432, in getSpmStatus lVer, spmId = self.masterDomain.inquireClusterLock() File "/usr/lib/python2.7/site-packages/vdsm/storage/sd.py", line 853, in inquireClusterLock return self._manifest.inquireDomainLock() File "/usr/lib/python2.7/site-packages/vdsm/storage/sd.py", line 524, in inquireDomainLock return self._domainLock.inquire(self.getDomainLease()) File "/usr/lib/python2.7/site-packages/vdsm/storage/clusterlock.py", line 418, in inquire resource = sanlock.read_resource(lease.path, lease.offset) SanlockException: (-202, 'Sanlock resource read failure', 'IO timeout') 2018-07-11 12:34:20,353+0300 DEBUG (jsonrpc/2) [storage.TaskManager.Task] (Task='9c3b94ea-359d-4221-838b-ae402dffe840') Task._run: 9c3b94ea-359d-4221-838b-ae402dffe840 ('f1d33b98-1d64-484c-b6d7-e101293ea211',) {} failed - stopping task (task:894) Engine log: -------------------------------- 2018-07-11 12:34:12,643+03 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.GetVolumeInfoVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-80) [f87df63e-54ac-4eac-8a91-6d15437bf997] START, GetVolumeInfoVDSCommand(HostName = host_mixed_1, GetVolumeInfoVDSCommandParameters:{hostId='f3c29124-ed63-4026-b5a6-8434fdd54ad3', storagePoolId='f1d33b98-1d64-484c-b6d7-e101293ea211', storageDomainId='9c2351bd-c4cc-436c-82f0-7e3ba8fd1718', imageGroupId='7c981ee3-781e-4822-a22c-f98be412b569', imageId='3892ce38-1434-4e4b-a371-b15d5a41f8af'}), log id: 3cd5061e 2018-07-11 12:34:20,359+03 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStatusVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-2) [] Failed in 'SpmStatusVDS' method 2018-07-11 12:34:20,365+03 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedThreadFactory-engineScheduled-Thread-2) [] EVENT_ID: VDS_BROKER_COMMAND_FAILURE(10,802), VDSM host_mixed_1 command SpmStatusVDS failed: (-202, 'Sanlock resource read failure', 'IO timeout') 2018-07-11 12:34:20,366+03 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStatusVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-2) [] Command 'SpmStatusVDSCommand(HostName = host_mixed_1, SpmStatusVDSCommandParameters:{hostId='f3c29124-ed63-4026-b5a6-8434fdd54ad3', storagePoolId='f1d33b98-1d64-484c-b6d7-e101293ea211'})' execution failed: VDSGenericException: VDSErrorException: Failed to SpmStatusVDS, error = (-202, 'Sanlock resource read failure', 'IO timeout'), code = 100 2018-07-11 12:34:20,385+03 INFO [org.ovirt.engine.core.bll.storage.pool.SetStoragePoolStatusCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-2) [df8df27] Running command: SetStoragePoolStatusCommand internal: true. Entities affected : ID: f1d33b98-1d64-484c-b6d7-e101293ea211 Type: StoragePool 2018-07-11 12:34:20,391+03 INFO [org.ovirt.engine.core.vdsbroker.storage.StoragePoolDomainHelper] (EE-ManagedThreadFactory-engineScheduled-Thread-2) [df8df27] Storage Pool 'f1d33b98-1d64-484c-b6d7-e101293ea211' - Updating Storage Domain 'd49d92db-da25-4a74-9f86-df2af8d32f6d' status from 'Active' to 'Unknown', reason: null 2018-07-11 12:34:20,393+03 INFO [org.ovirt.engine.core.vdsbroker.storage.StoragePoolDomainHelper] (EE-ManagedThreadFactory-engineScheduled-Thread-2) [df8df27] Storage Pool 'f1d33b98-1d64-484c-b6d7-e101293ea211' - Updating Storage Domain 'a5e83d19-8c03-4e5f-8c5d-58840d248d91' status from 'Active' to 'Unknown', reason: null 2018-07-11 12:34:20,393+03 INFO [org.ovirt.engine.core.vdsbroker.storage.StoragePoolDomainHelper] (EE-ManagedThreadFactory-engineScheduled-Thread-2) [df8df27] Storage Pool 'f1d33b98-1d64-484c-b6d7-e101293ea211' - Updating Storage Domain 'd9028448-7b51-47c2-8bb2-96f009f7f9bc' status from 'Active' to 'Unknown', reason: null 2018-07-11 12:34:20,394+03 INFO [org.ovirt.engine.core.vdsbroker.storage.StoragePoolDomainHelper] (EE-ManagedThreadFactory-engineScheduled-Thread-2) [df8df27] Storage Pool 'f1d33b98-1d64-484c-b6d7-e101293ea211' - Updating Storage Domain 'e00ada1f-2a0b-4234-a5bd-b73549a04290' status from 'Active' to 'Unknown', reason: null 2018-07-11 12:34:20,394+03 INFO [org.ovirt.engine.core.vdsbroker.storage.StoragePoolDomainHelper] (EE-ManagedThreadFactory-engineScheduled-Thread-2) [df8df27] Storage Pool 'f1d33b98-1d64-484c-b6d7-e101293ea211' - Updating Storage Domain '7de36e30-1066-416f-862c-bb47983b80e9' status from 'Active' to 'Unknown', reason: null 2018-07-11 12:34:20,395+03 INFO [org.ovirt.engine.core.vdsbroker.storage.StoragePoolDomainHelper] (EE-ManagedThreadFactory-engineScheduled-Thread-2) [df8df27] Storage Pool 'f1d33b98-1d64-484c-b6d7-e101293ea211' - Updating Storage Domain 'd31037e5-0d45-4306-975b-73eea845ae86' status from 'Active' to 'Unknown', reason: null 2018-07-11 12:34:20,396+03 INFO [org.ovirt.engine.core.vdsbroker.storage.StoragePoolDomainHelper] (EE-ManagedThreadFactory-engineScheduled-Thread-2) [df8df27] Storage Pool 'f1d33b98-1d64-484c-b6d7-e101293ea211' - Updating Storage Domain '952b1bc3-da8a-46a3-94fb-560db6bcca00' status from 'Active' to 'Unknown', reason: null 2018-07-11 12:34:20,396+03 INFO [org.ovirt.engine.core.vdsbroker.storage.StoragePoolDomainHelper] (EE-ManagedThreadFactory-engineScheduled-Thread-2) [df8df27] Storage Pool 'f1d33b98-1d64-484c-b6d7-e101293ea211' - Updating Storage Domain 'edad1292-185c-435b-8da3-84d706284b8f' status from 'Active' to 'Unknown', reason: null 2018-07-11 12:34:20,396+03 INFO [org.ovirt.engine.core.vdsbroker.storage.StoragePoolDomainHelper] (EE-ManagedThreadFactory-engineScheduled-Thread-2) [df8df27] Storage Pool 'f1d33b98-1d64-484c-b6d7-e101293ea211' - Updating Storage Domain 'bb4af7a9-3015-4b37-8984-039da776fcb7' status from 'Active' to 'Unknown', reason: null 2018-07-11 12:34:20,397+03 INFO [org.ovirt.engine.core.vdsbroker.storage.StoragePoolDomainHelper] (EE-ManagedThreadFactory-engineScheduled-Thread-2) [df8df27] Storage Pool 'f1d33b98-1d64-484c-b6d7-e101293ea211' - Updating Storage Domain '9c2351bd-c4cc-436c-82f0-7e3ba8fd1718' status from 'Active' to 'Unknown', reason: null 2018-07-11 12:34:20,397+03 INFO [org.ovirt.engine.core.vdsbroker.storage.StoragePoolDomainHelper] (EE-ManagedThreadFactory-engineScheduled-Thread-2) [df8df27] Storage Pool 'f1d33b98-1d64-484c-b6d7-e101293ea211' - Updating Storage Domain '21d2a96b-6b5e-43f4-9e54-ee939f326f74' status from 'Active' to 'Unknown', reason: null 2018-07-11 12:34:20,417+03 WARN [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedThreadFactory-engineScheduled-Thread-2) [df8df27] EVENT_ID: SYSTEM_CHANGE_STORAGE_POOL_STATUS_PROBLEMATIC_WITH_ERROR(987), Invalid status on Data Center golden_env_mixed. Setting Data Center status to Non Responsive (On host host_mixed_1, Error: General Exception). 2018-07-11 12:34:20,464+03 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStoragePoolVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-2) [df8df27] START, ConnectStoragePoolVDSCommand(HostName = host_mixed_1, ConnectStoragePoolVDSCommandParameters:{hostId='f3c29124-ed63-4026-b5a6-8434fdd54ad3', vdsId='f3c29124-ed63-4026-b5a6-8434fdd54ad3', storagePoolId='f1d33b98-1d64-484c-b6d7-e101293ea211', masterVersion='4'}), log id: 5d611d8b 2018-07-11 12:34:20,464+03 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStoragePoolVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-2) [df8df27] Executing with domain map: {21d2a96b-6b5e-43f4-9e54-ee939f326f74=active, e00ada1f-2a0b-4234-a5bd-b73549a04290=active, bb4af7a9-3015-4b37-8984-039da776fcb7=active, d31037e5-0d45-4306-975b-73eea845ae86=active, edad1292-185c-435b-8da3-84d706284b8f=active, 4c0908f9-3250-4bfa-9618-5f135d1bf099=attached, a5e83d19-8c03-4e5f-8c5d-58840d248d91=active, 9c2351bd-c4cc-436c-82f0-7e3ba8fd1718=active, 7de36e30-1066-416f-862c-bb47983b80e9=active, d49d92db-da25-4a74-9f86-df2af8d32f6d=active, 952b1bc3-da8a-46a3-94fb-560db6bcca00=active, d9028448-7b51-47c2-8bb2-96f009f7f9bc=active, 2d7c83a4-684c-4212-a5b7-363fb994d784=attached} 2018-07-11 12:34:30,061+03 WARN [org.ovirt.engine.core.vdsbroker.irsbroker.IrsProxy] (EE-ManagedThreadFactory-engine-Thread-59763) [] domain '9c2351bd-c4cc-436c-82f0-7e3ba8fd1718:iscsi_2' in problem 'PROBLEMATIC'. vds: 'host_mixed_1' 2018-07-11 12:34:30,062+03 WARN [org.ovirt.engine.core.vdsbroker.irsbroker.IrsProxy] (EE-ManagedThreadFactory-engine-Thread-59763) [] domain '21d2a96b-6b5e-43f4-9e54-ee939f326f74:dr_source1' in problem 'PROBLEMATIC'. vds: 'host_mixed_1' 2018-07-11 12:34:30,063+03 WARN [org.ovirt.engine.core.vdsbroker.irsbroker.IrsProxy] (EE-ManagedThreadFactory-engine-Thread-59763) [] domain 'bb4af7a9-3015-4b37-8984-039da776fcb7:iscsi_1' in problem 'PROBLEMATIC'. vds: 'host_mixed_1' 2018-07-11 12:34:30,063+03 WARN [org.ovirt.engine.core.vdsbroker.irsbroker.IrsProxy] (EE-ManagedThreadFactory-engine-Thread-59763) [] domain 'edad1292-185c-435b-8da3-84d706284b8f:iscsi_0' in problem 'PROBLEMATIC'. vds: 'host_mixed_1' 2018-07-11 12:34:39,306+03 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE-ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'default' is using 0 threads out of 1, 5 threads waiting for tasks. 2018-07-11 12:34:39,306+03 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE-ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'engine' is using 0 threads out of 500, 9 threads waiting for tasks and 0 tasks in queue. 2018-07-11 12:34:39,306+03 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE-ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'engineScheduled' is using 0 threads out of 100, 100 threads waiting for tasks. 2018-07-11 12:34:39,306+03 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE-ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'engineThreadMonitoring' is using 1 threads out of 1, 0 threads waiting for tasks. 2018-07-11 12:34:39,307+03 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE-ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'hostUpdatesChecker' is using 0 threads out of 5, 3 threads waiting for tasks. 2018-07-11 12:34:50,564+03 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.GetVolumeInfoVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-80) [f87df63e-54ac-4eac-8a91-6d15437bf997] Failed building DiskImage: candidate can not be null please use static method createGuidFromString 2018-07-11 12:34:50,565+03 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.GetVolumeInfoVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-80) [f87df63e-54ac-4eac-8a91-6d15437bf997] Command 'org.ovirt.engine.core.vdsbroker.vdsbroker.GetVolumeInfoVDSCommand' return value ' VolumeInfoReturn:{status='Status [code=0, message=Done]'} status = INVALID truesize = 0 apparentsize = 0 children: [] ' 2018-07-11 12:34:50,565+03 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.GetVolumeInfoVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-80) [f87df63e-54ac-4eac-8a91-6d15437bf997] HostName = host_mixed_1 2018-07-11 12:34:50,565+03 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.GetVolumeInfoVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-80) [f87df63e-54ac-4eac-8a91-6d15437bf997] FINISH, GetVolumeInfoVDSCommand, log id: 3cd5061e 2018-07-11 12:34:50,565+03 ERROR [org.ovirt.engine.core.bll.storage.disk.image.CopyDataCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-80) [f87df63e-54ac-4eac-8a91-6d15437bf997] Command 'org.ovirt.engine.core.bll.storage.disk.image.CopyDataCommand' failed: null 2018-07-11 12:34:50,565+03 ERROR [org.ovirt.engine.core.bll.storage.disk.image.CopyDataCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-80) [f87df63e-54ac-4eac-8a91-6d15437bf997] Exception: java.lang.NullPointerException at org.ovirt.engine.core.bll.storage.disk.image.CopyDataCommand.completeGenerationInfo(CopyDataCommand.java:57) [bll.jar:] at org.ovirt.engine.core.bll.storage.disk.image.CopyDataCommand.executeCommand(CopyDataCommand.java:40) [bll.jar:] at org.ovirt.engine.core.bll.CommandBase.executeWithoutTransaction(CommandBase.java:1133) [bll.jar:] at org.ovirt.engine.core.bll.CommandBase.executeActionInTransactionScope(CommandBase.java:1285) [bll.jar:] at org.ovirt.engine.core.bll.CommandBase.runInTransaction(CommandBase.java:1934) [bll.jar:] at org.ovirt.engine.core.utils.transaction.TransactionSupport.executeInSuppressed(TransactionSupport.java:164) [utils.jar:] at org.ovirt.engine.core.utils.transaction.TransactionSupport.executeInScope(TransactionSupport.java:103) [utils.jar:] at org.ovirt.engine.core.bll.CommandBase.execute(CommandBase.java:1345) [bll.jar:] at org.ovirt.engine.core.bll.CommandBase.executeAction(CommandBase.java:400) [bll.jar:] at org.ovirt.engine.core.bll.executor.DefaultBackendActionExecutor.execute(DefaultBackendActionExecutor.java:13) [bll.jar:] at org.ovirt.engine.core.bll.Backend.runAction(Backend.java:468) [bll.jar:] at org.ovirt.engine.core.bll.Backend.runActionImpl(Backend.java:450) [bll.jar:] at org.ovirt.engine.core.bll.Backend.runInternalAction(Backend.java:656) [bll.jar:] at sun.reflect.GeneratedMethodAccessor150.invoke(Unknown Source) [:1.8.0_171] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.8.0_171] at java.lang.reflect.Method.invoke(Method.java:498) [rt.jar:1.8.0_171] at org.jboss.as.ee.component.ManagedReferenceMethodInterceptor.processInvocation(ManagedReferenceMethodInterceptor.java:52) at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422) at org.jboss.invocation.InterceptorContext$Invocation.proceed(InterceptorContext.java:509) at org.jboss.as.weld.interceptors.Jsr299BindingsInterceptor.delegateInterception(Jsr299BindingsInterceptor.java:78) at org.jboss.as.weld.interceptors.Jsr299BindingsInterceptor.doMethodInterception(Jsr299BindingsInterceptor.java:88) at org.jboss.as.weld.interceptors.Jsr299BindingsInterceptor.processInvocation(Jsr299BindingsInterceptor.java:101) at org.jboss.as.ee.component.interceptors.UserInterceptorFactory$1.processInvocation(UserInterceptorFactory.java:63) at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422) at org.jboss.as.ejb3.component.invocationmetrics.ExecutionTimeInterceptor.processInvocation(ExecutionTimeInterceptor.java:43) [wildfly-ejb3-7.1.3.GA-redhat-2.jar:7.1.3.GA-redhat-2] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422) at org.jboss.as.ee.concurrent.ConcurrentContextInterceptor.processInvocation(ConcurrentContextInterceptor.java:45) [wildfly-ee-7.1.3.GA-redhat-2.jar:7.1.3.GA-redhat-2] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422) at org.jboss.invocation.InitialInterceptor.processInvocation(InitialInterceptor.java:40) at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422) at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:53) at org.jboss.as.ee.component.interceptors.ComponentDispatcherInterceptor.processInvocation(ComponentDispatcherInterceptor.java:52) at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422) at org.jboss.as.ejb3.component.singleton.SingletonComponentInstanceAssociationInterceptor.processInvocation(SingletonComponentInstanceAssociationInterceptor.java:53) [wildfly-ejb3-7.1.3.GA-redhat-2.jar:7.1.3.GA-redhat-2] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422) at org.jboss.as.ejb3.tx.CMTTxInterceptor.invokeInNoTx(CMTTxInterceptor.java:264) [wildfly-ejb3-7.1.3.GA-redhat-2.jar:7.1.3.GA-redhat-2] at org.jboss.as.ejb3.tx.CMTTxInterceptor.supports(CMTTxInterceptor.java:379) [wildfly-ejb3-7.1.3.GA-redhat-2.jar:7.1.3.GA-redhat-2] at org.jboss.as.ejb3.tx.CMTTxInterceptor.processInvocation(CMTTxInterceptor.java:244) [wildfly-ejb3-7.1.3.GA-redhat-2.jar:7.1.3.GA-redhat-2] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422) at org.jboss.invocation.InterceptorContext$Invocation.proceed(InterceptorContext.java:509) at org.jboss.weld.ejb.AbstractEJBRequestScopeActivationInterceptor.aroundInvoke(AbstractEJBRequestScopeActivationInterceptor.java:73) [weld-core-impl.jar:2.4.7.Final-redhat-1] at org.jboss.as.weld.ejb.EjbRequestScopeActivationInterceptor.processInvocation(EjbRequestScopeActivationInterceptor.java:89) at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422) at org.jboss.as.ejb3.component.interceptors.CurrentInvocationContextInterceptor.processInvocation(CurrentInvocationContextInterceptor.java:41) [wildfly-ejb3-7.1.3.GA-redhat-2.jar:7.1.3.GA-redhat-2] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422) at org.jboss.as.ejb3.component.invocationmetrics.WaitTimeInterceptor.processInvocation(WaitTimeInterceptor.java:47) [wildfly-ejb3-7.1.3.GA-redhat-2.jar:7.1.3.GA-redhat-2] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422) at org.jboss.as.ejb3.security.SecurityContextInterceptor.processInvocation(SecurityContextInterceptor.java:100) [wildfly-ejb3-7.1.3.GA-redhat-2.jar:7.1.3.GA-redhat-2] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422) at org.jboss.as.ejb3.deployment.processors.StartupAwaitInterceptor.processInvocation(StartupAwaitInterceptor.java:22) [wildfly-ejb3-7.1.3.GA-redhat-2.jar:7.1.3.GA-redhat-2] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422) at org.jboss.as.ejb3.component.interceptors.ShutDownInterceptorFactory$1.processInvocation(ShutDownInterceptorFactory.java:64) [wildfly-ejb3-7.1.3.GA-redhat-2.jar:7.1.3.GA-redhat-2] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422) at org.jboss.as.ejb3.component.interceptors.LoggingInterceptor.processInvocation(LoggingInterceptor.java:67) [wildfly-ejb3-7.1.3.GA-redhat-2.jar:7.1.3.GA-redhat-2] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422) at org.jboss.as.ee.component.NamespaceContextInterceptor.processInvocation(NamespaceContextInterceptor.java:50) at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422) at org.jboss.invocation.ContextClassLoaderInterceptor.processInvocation(ContextClassLoaderInterceptor.java:60) at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422) at org.jboss.invocation.InterceptorContext.run(InterceptorContext.java:438) at org.wildfly.security.manager.WildFlySecurityManager.doChecked(WildFlySecurityManager.java:609) at org.jboss.invocation.AccessCheckingInterceptor.processInvocation(AccessCheckingInterceptor.java:57) at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422) at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:53) at org.jboss.as.ee.component.ViewService$View.invoke(ViewService.java:198) at org.jboss.as.ee.component.ViewDescription$1.processInvocation(ViewDescription.java:185) at org.jboss.as.ee.component.ProxyInvocationHandler.invoke(ProxyInvocationHandler.java:81) at org.ovirt.engine.core.bll.interfaces.BackendInternal$$$view2.runInternalAction(Unknown Source) [bll.jar:] at sun.reflect.GeneratedMethodAccessor149.invoke(Unknown Source) [:1.8.0_171] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.8.0_171] at java.lang.reflect.Method.invoke(Method.java:498) [rt.jar:1.8.0_171] at org.jboss.weld.util.reflection.Reflections.invokeAndUnwrap(Reflections.java:433) [weld-core-impl.jar:2.4.7.Final-redhat-1] at org.jboss.weld.bean.proxy.EnterpriseBeanProxyMethodHandler.invoke(EnterpriseBeanProxyMethodHandler.java:133) [weld-core-impl.jar:2.4.7.Final-redhat-1] at org.jboss.weld.bean.proxy.EnterpriseTargetBeanInstance.invoke(EnterpriseTargetBeanInstance.java:56) [weld-core-impl.jar:2.4.7.Final-redhat-1] at org.jboss.weld.bean.proxy.InjectionPointPropagatingEnterpriseTargetBeanInstance.invoke(InjectionPointPropagatingEnterpriseTargetBeanInstance.java:67) [weld-core-impl.jar:2.4.7.Final-redhat-1] at org.jboss.weld.bean.proxy.ProxyMethodHandler.invoke(ProxyMethodHandler.java:100) [weld-core-impl.jar:2.4.7.Final-redhat-1] at org.ovirt.engine.core.bll.BackendCommandObjectsHandler$BackendInternal$BackendLocal$2049259618$Proxy$_$$_Weld$EnterpriseProxy$.runInternalAction(Unknown Source) [bll.jar:] at org.ovirt.engine.core.bll.CommandBase.runInternalAction(CommandBase.java:2324) [bll.jar:] at org.ovirt.engine.core.bll.CommandBase.runInternalActionWithTasksContext(CommandBase.java:2349) [bll.jar:] at org.ovirt.engine.core.bll.CommandBase.runInternalActionWithTasksContext(CommandBase.java:2344) [bll.jar:] at org.ovirt.engine.core.bll.storage.disk.image.CopyImageGroupVolumesDataCommand.copyVolumeData(CopyImageGroupVolumesDataCommand.java:112) [bll.jar:] at org.ovirt.engine.core.bll.storage.disk.image.CopyImageGroupVolumesDataCommand.performNextOperation(CopyImageGroupVolumesDataCommand.java:97) [bll.jar:] at org.ovirt.engine.core.bll.SerialChildCommandsExecutionCallback.childCommandsExecutionEnded(SerialChildCommandsExecutionCallback.java:32) [bll.jar:] at org.ovirt.engine.core.bll.ChildCommandsCallbackBase.doPolling(ChildCommandsCallbackBase.java:68) [bll.jar:] at org.ovirt.engine.core.bll.tasks.CommandCallbacksPoller.invokeCallbackMethodsImpl(CommandCallbacksPoller.java:146) [bll.jar:] at org.ovirt.engine.core.bll.tasks.CommandCallbacksPoller.invokeCallbackMethods(CommandCallbacksPoller.java:107) [bll.jar:] at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [rt.jar:1.8.0_171] at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) [rt.jar:1.8.0_171] at org.glassfish.enterprise.concurrent.internal.ManagedScheduledThreadPoolExecutor$ManagedScheduledFutureTask.access$201(ManagedScheduledThreadPoolExecutor.java:383) [javax.enterprise.concurrent.jar:1.0.0.redhat-1] at org.glassfish.enterprise.concurrent.internal.ManagedScheduledThreadPoolExecutor$ManagedScheduledFutureTask.run(ManagedScheduledThreadPoolExecutor.java:534) [javax.enterprise.concurrent.jar:1.0.0.redhat-1] 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] at org.glassfish.enterprise.concurrent.ManagedThreadFactoryImpl$ManagedThread.run(ManagedThreadFactoryImpl.java:250) [javax.enterprise.concurrent.jar:1.0.0.redhat-1] at org.jboss.as.ee.concurrent.service.ElytronManagedThreadFactory$ElytronManagedThread.run(ElytronManagedThreadFactory.java:78) 2018-07-11 12:34:50,753+03 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedThreadFactory-engineScheduled-Thread-2) [df8df27] EVENT_ID: VDS_BROKER_COMMAND_FAILURE(10,802), VDSM host_mixed_1 command ConnectStoragePoolVDS failed: Cannot find master domain: 'spUUID=f1d33b98-1d64-484c-b6d7-e101293ea211, msdUUID=bb4af7a9-3015-4b37-8984-039da776fcb7' 2018-07-11 12:34:50,753+03 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStoragePoolVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-2) [df8df27] Command 'org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStoragePoolVDSCommand' return value 'StatusOnlyReturn [status=Status [code=304, message=Cannot find master domain: 'spUUID=f1d33b98-1d64-484c-b6d7-e101293ea211, msdUUID=bb4af7a9-3015-4b37-8984-039da776fcb7']]' 2018-07-11 12:34:50,753+03 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStoragePoolVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-2) [df8df27] HostName = host_mixed_1 2018-07-11 12:34:50,753+03 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStoragePoolVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-2) [df8df27] Command 'ConnectStoragePoolVDSCommand(HostName = host_mixed_1, ConnectStoragePoolVDSCommandParameters:{hostId='f3c29124-ed63-4026-b5a6-8434fdd54ad3', vdsId='f3c29124-ed63-4026-b5a6-8434fdd54ad3', storagePoolId='f1d33b98-1d64-484c-b6d7-e101293ea211', masterVersion='4'})' execution failed: IRSGenericException: IRSErrorException: IRSNoMasterDomainException: Cannot find master domain: 'spUUID=f1d33b98-1d64-484c-b6d7-e101293ea211, msdUUID=bb4af7a9-3015-4b37-8984-039da776fcb7' 2018-07-11 12:34:50,753+03 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStoragePoolVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-2) [df8df27] FINISH, ConnectStoragePoolVDSCommand, log id: 5d611d8b 2018-07-11 12:34:50,753+03 ERROR [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-2) [df8df27] IrsBroker::Failed::GetStoragePoolInfoVDS: IRSGenericException: IRSErrorException: IRSNoMasterDomainException: Cannot find master domain: 'spUUID=f1d33b98-1d64-484c-b6d7-e101293ea211, msdUUID=bb4af7a9-3015-4b37-8984-039da776fcb7' DisconnectStoragePoolVDSCommand(HostName