Bug 1656742

Summary: NPE- Hosted engine DisconnectHostFromStoragePoolServersCommand' failed: EngineException: java.lang.NullPointerException (Failed with error ENGINE and code 5001)
Product: [oVirt] ovirt-engine Reporter: Avihai <aefrat>
Component: BLL.StorageAssignee: Ahmad Khiet <akhiet>
Status: CLOSED DUPLICATE QA Contact: Avihai <aefrat>
Severity: medium Docs Contact:
Priority: unspecified    
Version: 4.2.7.1CC: bugs
Target Milestone: ovirt-4.4.0Flags: pm-rhel: ovirt-4.4+
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: 2019-11-06 13:43:21 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:
Description Flags
engine and vdsm logs none

Description Avihai 2018-12-06 08:55:35 UTC
Created attachment 1511996 [details]
engine and vdsm logs

Description of problem:
Running automation TestCase18976 scenario,
During scenario the removal of a host running HE-VM, reaching DisconnectHostFromStoragePoolServersCommand' failed: EngineException: java.lang.NullPointerException (Failed with error ENGINE and code 5001)


Engine:
2018-11-30 23:22:31,855+02 INFO  [org.ovirt.engine.core.vdsbroker.RemoveVdsVDSCommand] (default task-17) [hosts_delete_fcdf92d7-2fe2-411f] START, RemoveVdsVDSCommand( RemoveVdsVDSCommandParameters:{hostId='831ed
385-b02e-4997-8695-7d59b3d5f66d'}), log id: 11dd1558
2018-11-30 23:22:32,546+02 INFO  [org.ovirt.engine.core.vdsbroker.monitoring.VmAnalyzer] (EE-ManagedThreadFactory-engineScheduled-Thread-36) [] VM '62933e7b-12d8-481d-b487-5db0deefb10d'(vm_TestCase18976_30231753
87) moved from 'MigratingTo' --> 'Up'
2018-11-30 23:22:32,592+02 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedThreadFactory-engineScheduled-Thread-36) [] EVENT_ID: VM_MIGRATION_DONE(63), Migration completed
 (VM: vm_TestCase18976_3023175387, Source: host_mixed_1, Destination: host_mixed_3, Duration: 11 seconds, Total: 21 seconds, Actual downtime: 189ms)
2018-11-30 23:22:32,594+02 INFO  [org.ovirt.engine.core.bll.MigrateVmCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-36) [] Lock freed to object 'EngineLock:{exclusiveLocks='[62933e7b-12d8-481d-b487-5db
0deefb10d=VM]', sharedLocks=''}'
2018-11-30 23:22:34,488+02 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.DisconnectStorageServerVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-92) [270b4f55] FINISH, DisconnectStorageServerVDSCom
mand, return: {8c9ba560-8ccd-4978-87c6-1c215b71c80a=0}, log id: 2b24d9ae
2018-11-30 23:22:34,527+02 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.DisconnectStorageServerVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-92) [270b4f55] START, DisconnectStorageServerVDSComm
and(HostName = host_mixed_1, StorageServerConnectionManagementVDSParameters:{hostId='831ed385-b02e-4997-8695-7d59b3d5f66d', storagePoolId='0eb26d28-f47f-11e8-aa63-001a4a168bfc', storageType='GLUSTERFS', connecti
onList='[StorageServerConnections:{id='62f0b21a-6d4e-4db8-be93-965cf6f28f1e', connection='gluster01.lab.eng.tlv2.redhat.com:/GE_he6_volume01', iqn='null', vfsType='glusterfs', mountOptions='null', nfsVersion='null', nfsRetrans='null', nfsTimeo='null', iface='null', netIfaceName='null'}, StorageServerConnections:{id='8679ed4a-824e-4d59-97b6-ffba6e82b549', connection='gluster01.lab.eng.tlv2.redhat.com:/GE_he6_volume02', iqn='null', vfsType='glusterfs', mountOptions='null', nfsVersion='null', nfsRetrans='null', nfsTimeo='null', iface='null', netIfaceName='null'}, StorageServerConnections:{id='acedda63-bb97-4939-9512-912d34ef1ed9', connection='gluster01.lab.eng.tlv2.redhat.com:/GE_he6_volume03', iqn='null', vfsType='glusterfs', mountOptions='null', nfsVersion='null', nfsRetrans='null', nfsTimeo='null', iface='null', netIfaceName='null'}]', sendNetworkEventOnFailure='true'}), log id: 57378200
2018-11-30 23:22:34,529+02 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.DisconnectStorageServerVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-92) [270b4f55] Failed in 'DisconnectStorageServerVDS' method, for vds: 'host_mixed_1'; host: 'lynx22.lab.eng.tlv2.redhat.com': null
2018-11-30 23:22:34,530+02 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.DisconnectStorageServerVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-92) [270b4f55] Command 'DisconnectStorageServerVDSCommand(HostName = host_mixed_1, StorageServerConnectionManagementVDSParameters:{hostId='831ed385-b02e-4997-8695-7d59b3d5f66d', storagePoolId='0eb26d28-f47f-11e8-aa63-001a4a168bfc', storageType='GLUSTERFS', connectionList='[StorageServerConnections:{id='62f0b21a-6d4e-4db8-be93-965cf6f28f1e', connection='gluster01.lab.eng.tlv2.redhat.com:/GE_he6_volume01', iqn='null', vfsType='glusterfs', mountOptions='null', nfsVersion='null', nfsRetrans='null', nfsTimeo='null', iface='null', netIfaceName='null'}, StorageServerConnections:{id='8679ed4a-824e-4d59-97b6-ffba6e82b549', connection='gluster01.lab.eng.tlv2.redhat.com:/GE_he6_volume02', iqn='null', vfsType='glusterfs', mountOptions='null', nfsVersion='null', nfsRetrans='null', nfsTimeo='null', iface='null', netIfaceName='null'}, StorageServerConnections:{id='acedda63-bb97-4939-9512-912d34ef1ed9', connection='gluster01.lab.eng.tlv2.redhat.com:/GE_he6_volume03', iqn='null', vfsType='glusterfs', mountOptions='null', nfsVersion='null', nfsRetrans='null', nfsTimeo='null', iface='null', netIfaceName='null'}]', sendNetworkEventOnFailure='true'})' execution failed: null
2018-11-30 23:22:34,530+02 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.DisconnectStorageServerVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-92) [270b4f55] FINISH, DisconnectStorageServerVDSCommand, log id: 57378200
2018-11-30 23:22:34,530+02 ERROR [org.ovirt.engine.core.bll.storage.pool.DisconnectHostFromStoragePoolServersCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-92) [270b4f55] Command 'org.ovirt.engine.core.bll.storage.pool.DisconnectHostFromStoragePoolServersCommand' failed: EngineException: java.lang.NullPointerException (Failed with error ENGINE and code 5001)


Version-Release number of selected component (if applicable):
ovirt-engine-4.2.8-0.1.el7ev.noarch
vdsm-4.20.44-1.el7ev.x86_64


How reproducible:
Happened once so far

Steps to Reproduce:

First, use HE environment with host_mixed_1 is the were the HE-VM ! 

Taken from automation log:
23:17:53 2018-11-30 23:17:53,873 INFO       Test Setup   1: Creating VM vm_TestCase18976_3023175387

23:18:07 2018-11-30 23:18:06,961 INFO       Test Setup   2: Starting VM vm_TestCase18976_3023175387

23:18:07 2018-11-30 23:18:06,964 INFO       Test Setup   3: [class] Start VM vm_TestCase18976_3023175387 with {'wait_for_ip': True, 'pause': False, 'use_cloud_init': False, 'timeout': 600, 'wait_for_status': 'up'}

23:20:51 2018-11-30 23:20:51,673 INFO       Test Setup   4: Creating disks with filesystem and attach to VM vm_TestCase18976_3023175387

23:22:10 2018-11-30 23:22:10,634 INFO       Test Setup   5: Removing host host_mixed_1 from the env

23:22:10 2018-11-30 23:22:10,751 INFO       Test Setup   6: [class] Deactivate the host host_mixed_1. with {'expected_status': 'maintenance'}

Actual results:
NPE- Hosted engine DisconnectHostFromStoragePoolServersCommand' failed: EngineException: java.lang.NullPointerException (Failed with error ENGINE and code 5001)

Expected results:
NPE should not appear.

Additional info:

Comment 1 Sandro Bonazzola 2019-01-28 09:34:06 UTC
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.

Comment 2 Ahmad Khiet 2019-11-03 14:10:21 UTC
can't reproduce. After inspecting the provided logs, it seems another issue which is not related to the flow caused this error, it seems that for an unclear reason, for now, there is an error in host_mixed_1, I think it's not related to the flow.
can you please try re-run the following test and update?

Comment 3 Avihai 2019-11-05 08:39:57 UTC
(In reply to Ahmad Khiet from comment #2)
> can't reproduce. After inspecting the provided logs, it seems another issue
> which is not related to the flow caused this error, it seems that for an
> unclear reason, for now, there is an error in host_mixed_1, I think it's not
> related to the flow.
> can you please try re-run the following test and update?

Hi Ahmad,
As the issue occurred only once I can not reproduce it.
What info are you missing? which logs? Do you must have a reproduced ENV for this issue.

Anyway, If there is nothing you can do with the provided logs please close this bug with 'INSUFFICAIENT_DATA' cause and add exactly what you are missing so the next time this occurs we can reopen and provide the missing logs/ENV.

If you believe this issue was caused by environment issues please close it as WORKSFORME and state why you belove it's an environmental issue.

Comment 4 Ahmad Khiet 2019-11-06 13:43:21 UTC

*** This bug has been marked as a duplicate of bug 1667723 ***