Hide Forgot
Created attachment 1208913 [details] vdsm.log of hypervisor Description of problem: With RHEV-M 4.0, I added hosts, added a new SCSI storage domain and tried to import an ISO domain. Got error message: Error while executing action Add Storage Connection: Problem while trying to mount target. I can mount target from engine to ISO mount location without RHEV- M. Version-Release number of selected component (if applicable): vdsm-4.18.15-1.el7ev.x86_64 Engine and hosts: http://download.eng.bos.redhat.com/released/RHEL-7/7.2/Server/x86_64/os/ http://download.eng.bos.redhat.com/released/RHEL-7/7.2/Server-optional/x86_64/os/ http://download.eng.bos.redhat.com/released/Supp-RHEL-7/7.2/Server/x86_64/os/ http://download.lab.bos.redhat.com/rel-eng/repos/rhel-7.2-z/x86_64/ http://bob.eng.lab.tlv.redhat.com/builds/4.0/4.0.5-1/el7 Engine: http://download.lab.bos.redhat.com/released/jboss/eap7/7.0.0/composes/JBEAP-7.0.0-RHEL-7/Server/x86_64/os/ Hosts: http://download.lab.bos.redhat.com/rel-eng/repos/rhevh-rhel-7.2-candidate/x86_64/ How reproducible: 100% Steps to Reproduce: 1. 2. 3. Actual results: Expected results: Additional info: This is the machine the ISO mount is located: [root@ns1 isos]# cat /etc/exports # /rhev/isos *(rw,sync,no_subtree_check,all_squash,anonuid=36,anongid=36) /rhev/isos *(rw,no_root_squash,anonuid=36,anongid=36) [root@ns1 ~]# mount | grep /rhev /dev/sdb1 on /rhev type ext4 (rw,relatime,seclabel,data=ordered) [root@ns1 ~]# [root@ns1 /]# ls -lat | grep rhev drwxr-xr-x. 4 vdsm kvm 4096 Apr 18 11:21 rhev [root@ns1 /]# [root@ns1 rhev]# ls -lat total 28 dr-xr-xr-x. 19 root root 4096 Oct 3 11:03 .. drwxr-xr-x. 3 vdsm kvm 4096 Jul 26 10:40 isos drwxr-xr-x. 4 vdsm kvm 4096 Apr 18 11:21 . drwxr-xr-x. 2 vdsm kvm 16384 Mar 30 2016 lost+found [root@ns1 rhev]# [root@ns1 isos]# ls -lat total 12 -rwxr-xr-x. 1 vdsm kvm 0 Sep 30 10:22 __DIRECT_IO_TEST__ drwxr-xr-x. 3 vdsm kvm 4096 Jul 26 10:40 . drwxr-xr-x. 4 vdsm kvm 4096 Apr 21 10:15 cac76132-083f-4f5b-911c-827891bf657a drwxr-xr-x. 4 vdsm kvm 4096 Apr 18 11:21 .. [root@ns1 isos]# This has a previous RHEV-M 4.0 install ISO location already installed and was previously working. engine.log tail: 2016-10-10 10:44:02,140 INFO [org.ovirt.engine.core.bll.storage.connection.AddStorageServerConnectionCommand] (default task-1) [2148987e] Lock Acquired to object 'EngineLock:{exclusiveLocks='[10.19.168.10:/rhev/isos=<STORAGE_CONNECTION, ACTION_TYPE_FAILED_OBJECT_LOCKED>]', sharedLocks='null'}' 2016-10-10 10:44:02,159 INFO [org.ovirt.engine.core.bll.storage.connection.AddStorageServerConnectionCommand] (default task-1) [2148987e] Running command: AddStorageServerConnectionCommand internal: false. Entities affected : ID: aaa00000-0000-0000-0000-123456789aaa Type: SystemAction group CREATE_STORAGE_DOMAIN with role type ADMIN 2016-10-10 10:44:02,161 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStorageServerVDSCommand] (default task-1) [2148987e] START, ConnectStorageServerVDSCommand(HostName = corrin, StorageServerConnectionManagementVDSParameters:{runAsync='true', hostId='8b47c601-35d8-434f-a565-c0853981c097', storagePoolId='00000000-0000-0000-0000-000000000000', storageType='NFS', connectionList='[StorageServerConnections:{id='null', connection='10.19.168.10:/rhev/isos', iqn='null', vfsType='null', mountOptions='null', nfsVersion='V3', nfsRetrans='null', nfsTimeo='null', iface='null', netIfaceName='null'}]'}), log id: 16b1fb16 2016-10-10 10:46:08,209 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStorageServerVDSCommand] (default task-1) [2148987e] FINISH, ConnectStorageServerVDSCommand, return: {00000000-0000-0000-0000-000000000000=477}, log id: 16b1fb16 2016-10-10 10:46:08,213 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (default task-1) [2148987e] Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: The error message for connection 10.19.168.10:/rhev/isos returned by VDSM was: Problem while trying to mount target 2016-10-10 10:46:08,213 ERROR [org.ovirt.engine.core.bll.storage.connection.BaseFsStorageHelper] (default task-1) [2148987e] The connection with details '10.19.168.10:/rhev/isos' failed because of error code '477' and error message is: problem while trying to mount target 2016-10-10 10:46:08,213 ERROR [org.ovirt.engine.core.bll.storage.connection.AddStorageServerConnectionCommand] (default task-1) [2148987e] Command 'org.ovirt.engine.core.bll.storage.connection.AddStorageServerConnectionCommand' failed: EngineException: ProblemWhileTryingToMountTarget (Failed with error ProblemWhileTryingToMountTarget and code 477) 2016-10-10 10:46:08,216 ERROR [org.ovirt.engine.core.bll.storage.connection.AddStorageServerConnectionCommand] (default task-1) [2148987e] Transaction rolled-back for command 'org.ovirt.engine.core.bll.storage.connection.AddStorageServerConnectionCommand'. 2016-10-10 10:46:08,237 INFO [org.ovirt.engine.core.bll.storage.connection.AddStorageServerConnectionCommand] (default task-1) [2148987e] Lock freed to object 'EngineLock:{exclusiveLocks='[10.19.168.10:/rhev/isos=<STORAGE_CONNECTION, ACTION_TYPE_FAILED_OBJECT_LOCKED>]', sharedLocks='null'}' 2016-10-10 10:46:08,541 INFO [org.ovirt.engine.core.bll.storage.connection.DisconnectStorageServerConnectionCommand] (default task-9) [2078c1fb] Running command: DisconnectStorageServerConnectionCommand internal: false. Entities affected : ID: aaa00000-0000-0000-0000-123456789aaa Type: SystemAction group CREATE_STORAGE_DOMAIN with role type ADMIN 2016-10-10 10:46:08,543 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.DisconnectStorageServerVDSCommand] (default task-9) [2078c1fb] START, DisconnectStorageServerVDSCommand(HostName = corrin, StorageServerConnectionManagementVDSParameters:{runAsync='true', hostId='8b47c601-35d8-434f-a565-c0853981c097', storagePoolId='00000000-0000-0000-0000-000000000000', storageType='NFS', connectionList='[StorageServerConnections:{id='null', connection='10.19.168.10:/rhev/isos', iqn='null', vfsType='null', mountOptions='null', nfsVersion='V3', nfsRetrans='null', nfsTimeo='null', iface='null', netIfaceName='null'}]'}), log id: 44083b6 2016-10-10 10:46:09,611 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.DisconnectStorageServerVDSCommand] (default task-9) [2078c1fb] FINISH, DisconnectStorageServerVDSCommand, return: {00000000-0000-0000-0000-000000000000=477}, log id: 44083b6 2016-10-10 10:48:32,938 INFO [org.ovirt.engine.core.bll.storage.ovfstore.OvfDataUpdater] (DefaultQuartzScheduler7) [30ec6097] Attempting to update VMs/Templates Ovf. 2016-10-10 10:48:32,941 INFO [org.ovirt.engine.core.bll.storage.ovfstore.ProcessOvfUpdateForStoragePoolCommand] (DefaultQuartzScheduler7) [51ab098c] Before acquiring and wait lock 'EngineLock:{exclusiveLocks='[57f79338-0268-023b-0224-000000000267=<OVF_UPDATE, ACTION_TYPE_FAILED_OBJECT_LOCKED>]', sharedLocks='null'}' 2016-10-10 10:48:32,941 INFO [org.ovirt.engine.core.bll.storage.ovfstore.ProcessOvfUpdateForStoragePoolCommand] (DefaultQuartzScheduler7) [51ab098c] Lock-wait acquired to object 'EngineLock:{exclusiveLocks='[57f79338-0268-023b-0224-000000000267=<OVF_UPDATE, ACTION_TYPE_FAILED_OBJECT_LOCKED>]', sharedLocks='null'}' 2016-10-10 10:48:32,941 INFO [org.ovirt.engine.core.bll.storage.ovfstore.ProcessOvfUpdateForStoragePoolCommand] (DefaultQuartzScheduler7) [51ab098c] Running command: ProcessOvfUpdateForStoragePoolCommand internal: true. Entities affected : ID: 57f79338-0268-023b-0224-000000000267 Type: StoragePool 2016-10-10 10:48:32,951 INFO [org.ovirt.engine.core.bll.storage.ovfstore.ProcessOvfUpdateForStoragePoolCommand] (DefaultQuartzScheduler7) [51ab098c] Attempting to update VM OVFs in Data Center 'Default' 2016-10-10 10:48:32,958 INFO [org.ovirt.engine.core.bll.storage.ovfstore.ProcessOvfUpdateForStoragePoolCommand] (DefaultQuartzScheduler7) [51ab098c] Successfully updated VM OVFs in Data Center 'Default' 2016-10-10 10:48:32,958 INFO [org.ovirt.engine.core.bll.storage.ovfstore.ProcessOvfUpdateForStoragePoolCommand] (DefaultQuartzScheduler7) [51ab098c] Attempting to update template OVFs in Data Center 'Default' 2016-10-10 10:48:32,961 INFO [org.ovirt.engine.core.bll.storage.ovfstore.ProcessOvfUpdateForStoragePoolCommand] (DefaultQuartzScheduler7) [51ab098c] Successfully updated templates OVFs in Data Center 'Default' 2016-10-10 10:48:32,961 INFO [org.ovirt.engine.core.bll.storage.ovfstore.ProcessOvfUpdateForStoragePoolCommand] (DefaultQuartzScheduler7) [51ab098c] Attempting to remove unneeded template/vm OVFs in Data Center 'Default' 2016-10-10 10:48:32,965 INFO [org.ovirt.engine.core.bll.storage.ovfstore.ProcessOvfUpdateForStoragePoolCommand] (DefaultQuartzScheduler7) [51ab098c] Successfully removed unneeded template/vm OVFs in Data Center 'Default' 2016-10-10 10:48:32,965 INFO [org.ovirt.engine.core.bll.storage.ovfstore.ProcessOvfUpdateForStoragePoolCommand] (DefaultQuartzScheduler7) [51ab098c] Lock freed to object 'EngineLock:{exclusiveLocks='[57f79338-0268-023b-0224-000000000267=<OVF_UPDATE, ACTION_TYPE_FAILED_OBJECT_LOCKED>]', sharedLocks='null'}'
This is one of the hosts that could not connect with VDSM and it is connecting manually. 10.19.168.10:/rhev/isos on /home/test/tmpmnt type fuse.sshfs (rw,nosuid,nodev,relatime,user_id=0,group_id=0) [root@corrin test]#
According to the log, the mount times out. Please share your /var/log/messages and the mount command that succeeded manually.
This bug report has Keywords: Regression or TestBlocker. Since no regressions or test blockers are allowed between releases, it is also being identified as a blocker for this release. Please resolve ASAP.
I tailed the /var/log/messages and the tail is in the original post. In the tail, you will see that the "mount" to '10.19.168.10:/rhev/isos' is timing out. In comment 1, that "[root@corrin test]" machine is the hypervisor that is timing out in RHEV-M. I typed the mount command at the hypervisor and have shown that being mounted to the '10.19.168.10:/rhev/isos' dir, manually.
(In reply to Bill Sanford from comment #4) > I tailed the /var/log/messages and the tail is in the original post. In the > tail, you will see that the "mount" to '10.19.168.10:/rhev/isos' is timing > out. > > In comment 1, that "[root@corrin test]" machine is the hypervisor that is > timing out in RHEV-M. I typed the mount command at the hypervisor and have > shown that being mounted to the '10.19.168.10:/rhev/isos' dir, manually. Are you trying with fuse.sshfs ? (In reply to Bill Sanford from comment #1) > This is one of the hosts that could not connect with VDSM and it is > connecting manually. > > 10.19.168.10:/rhev/isos on /home/test/tmpmnt type fuse.sshfs Why is it with fuse.sshfs? > (rw,nosuid,nodev,relatime,user_id=0,group_id=0) > [root@corrin test]# Raz - has anyone reproduced this in storage QE?
I just tried to reproduce this and it works fine. Import of an ISO domain to my environment succeeded
Please reopen if you can supply the needed info.