Bug 1011193
| Summary: | iSCSI Discovery fails | ||||||||||||
|---|---|---|---|---|---|---|---|---|---|---|---|---|---|
| Product: | [Retired] oVirt | Reporter: | Jonas Israelsson <jonas> | ||||||||||
| Component: | ovirt-node | Assignee: | Joey Boggs <jboggs> | ||||||||||
| Status: | CLOSED CURRENTRELEASE | QA Contact: | bugs <bugs> | ||||||||||
| Severity: | high | Docs Contact: | |||||||||||
| Priority: | high | ||||||||||||
| Version: | 3.3 | CC: | acathrow, baumanmo, dwalsh, ecohen, fdeutsch, fromani, hadong, jboggs, leiwang, mgoldboi, ovirt-bugs, ovirt-maint, yeylon | ||||||||||
| Target Milestone: | --- | ||||||||||||
| Target Release: | 3.4.2 | ||||||||||||
| Hardware: | x86_64 | ||||||||||||
| OS: | Linux | ||||||||||||
| Whiteboard: | node | ||||||||||||
| Fixed In Version: | Doc Type: | Bug Fix | |||||||||||
| Doc Text: | Story Points: | --- | |||||||||||
| Clone Of: | Environment: | ||||||||||||
| Last Closed: | 2014-05-29 16:41:22 UTC | Type: | Bug | ||||||||||
| Regression: | --- | Mount Type: | --- | ||||||||||
| Documentation: | --- | CRM: | |||||||||||
| Verified Versions: | Category: | --- | |||||||||||
| oVirt Team: | --- | RHEL 7.3 requirements from Atomic Host: | |||||||||||
| Cloudforms Team: | --- | Target Upstream Version: | |||||||||||
| Embargoed: | |||||||||||||
| Bug Depends On: | 1025401 | ||||||||||||
| Bug Blocks: | |||||||||||||
| Attachments: |
|
||||||||||||
Created attachment 801844 [details]
Output from 'mount'
Created attachment 801847 [details]
Output from 'df -h'
Created attachment 801849 [details]
Output from 'find /var/lib/iscsi -ls'
ssh to the ovirt-node as root and doing a setenforce 0 is migitating the problem.
[root@ovirt-node vdsm]# audit2allow -alR
require {
type unconfined_t;
type sshd_net_t;
type tuned_t;
type virtd_t;
type iscsid_t;
type collectd_t;
type initrc_t;
type iscsi_var_lib_t;
class process dyntransition;
class unix_stream_socket connectto;
class lnk_file { create unlink };
class dir { write remove_name create add_name rmdir };
class file { write create unlink };
}
#============= collectd_t ==============
allow collectd_t virtd_t:unix_stream_socket connectto;
#============= initrc_t ==============
allow initrc_t sshd_net_t:process dyntransition;
allow initrc_t unconfined_t:process dyntransition;
#============= iscsid_t ==============
allow iscsid_t iscsi_var_lib_t:dir { write remove_name create add_name rmdir };
allow iscsid_t iscsi_var_lib_t:file { write create unlink };
allow iscsid_t iscsi_var_lib_t:lnk_file { create unlink };
#============= tuned_t ==============
shows this.
Dan, shall the above rules go into Fedora or shall we add them to our own (ovirt node) module? None of them seem to be specific to any of Node's quirks (e.g. tmpfs_t as a target, because Node is using much tmpfs stuff)- FWIW: The exact same thing happened to me on a 'regular' Fedora 19 Host (not an ovirt-node Host) within my ovirt env. In addition, the mitigation from Comment #4 worked well in my case too. This is an automated message. Re-targeting all non-blocker bugs still open on 3.4.0 to 3.4.1. this was fixed in 3.0.4 release, please reopen if it occurs again. |
Created attachment 801843 [details] dmesg output from the node Trying to add a new iscsi storage domain fails while doing the iscsi_discovery and the following error is written to the engine error log. 2013-09-23 19:45:49,855 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.DiscoverSendTargetsVDSCommand] (ajp--127.0.0.1-8702-14) START, DiscoverSendTargetsVDSCommand(HostName = bagaren, HostId = 3bb080e5-d36d-4376-9cc0-f2f0b00c1439, connection={ id: null, connection: 192.168.24.200, iqn: null, vfsType: null, mountOptions: null, nfsVersion: null, nfsRetrans: null, nfsTimeo: null };), log id: 13d14411 2013-09-23 19:45:49,888 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.DiscoverSendTargetsVDSCommand] (ajp--127.0.0.1-8702-14) Command org.ovirt.engine.core.vdsbroker.vdsbroker.DiscoverSendTargetsVDSCommand return value IQNListReturnForXmlRpc [mStatus=StatusForXmlRpc [mCode=475, mMessage=Failed discovery of iSCSI targets: "portal=IscsiPortal(hostname='192.168.24.200', port=3260), err=(6, [], ['iscsiadm: Could not make dir /var/lib/iscsi/send_targets/192.168.24.200,3260 err 13', '', 'iscsiadm: Could not open /var/lib/iscsi/send_targets/192.168.24.200,3260: Permission denied', '', 'iscsiadm: Could not add new discovery record.'])"]] 2013-09-23 19:45:49,912 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.DiscoverSendTargetsVDSCommand] (ajp--127.0.0.1-8702-14) HostName = bagaren 2013-09-23 19:45:49,915 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.DiscoverSendTargetsVDSCommand] (ajp--127.0.0.1-8702-14) Command DiscoverSendTargetsVDS execution failed. Exception: VDSErrorException: VDSGenericException: VDSErrorException: Failed in vdscommand to DiscoverSendTargetsVDS, error = Failed discovery of iSCSI targets: "portal=IscsiPortal(hostname='192.168.24.200', port=3260), err=(6, [], ['iscsiadm: Could not make dir /var/lib/iscsi/send_targets/192.168.24.200,3260 err 13', '', 'iscsiadm: Could not open /var/lib/iscsi/send_targets/192.168.24.200,3260: Permission denied', '', 'iscsiadm: Could not add new discovery record.'])" 2013-09-23 19:45:49,931 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.DiscoverSendTargetsVDSCommand] (ajp--127.0.0.1-8702-14) FINISH, DiscoverSendTargetsVDSCommand, log id: 13d14411 2013-09-23 19:45:49,936 ERROR [org.ovirt.engine.core.bll.storage.DiscoverSendTargetsQuery] (ajp--127.0.0.1-8702-14) Query DiscoverSendTargetsQuery failed. Exception message is VdcBLLException: org.ovirt.engine.core.vdsbroker.vdsbroker.VDSErrorException: VDSGenericException: VDSErrorException: Failed in vdscommand to DiscoverSendTargetsVDS, error = Failed discovery of iSCSI targets: "portal=IscsiPortal(hostname='192.168.24.200', port=3260), err=(6, [], ['iscsiadm: Could not make dir /var/lib/iscsi/send_targets/192.168.24.200,3260 err 13', '', 'iscsiadm: Could not open /var/lib/iscsi/send_targets/192.168.24.200,3260: Permission denied', '', 'iscsiadm: Could not add new discovery record.'])" (Failed with VDSM error iSCSIDiscoveryError and code 475) And this to the vdsm.log in the node. Thread-4103::DEBUG::2013-09-23 17:39:48,809::BindingXMLRPC::177::vds::(wrapper) client [192.168.24.217] Thread-4103::DEBUG::2013-09-23 17:39:48,810::task::579::TaskManager.Task::(_updateState) Task=`f49e993b-745c-4c91-800c-290331028bad`::moving from state init -> state preparing Thread-4103::INFO::2013-09-23 17:39:48,810::logUtils::44::dispatcher::(wrapper) Run and protect: discoverSendTargets(con={'connection': '192.168.24.200', 'password': '******', 'port': '3260', 'user': ''}, options=None) Thread-4103::DEBUG::2013-09-23 17:39:48,810::iscsiadm::91::Storage.Misc.excCmd::(_runCmd) '/usr/bin/sudo -n /sbin/iscsiadm -m discoverydb -t sendtargets -I default -p 192.168.24.200:3260 --op=new' (cwd None) Thread-4103::DEBUG::2013-09-23 17:39:48,820::iscsiadm::91::Storage.Misc.excCmd::(_runCmd) FAILED: <err> = 'iscsiadm: Could not make dir /var/lib/iscsi/send_targets/192.168.24.200,3260 err 13\n\niscsiadm: Could not open /var/lib/iscsi/send_targets/192.168.24.200,3260: Permission denied\n\niscsiadm: Could not add new discovery record.\n'; <rc> = 6 Thread-4103::DEBUG::2013-09-23 17:39:48,821::iscsiadm::91::Storage.Misc.excCmd::(_runCmd) '/usr/bin/sudo -n /sbin/iscsiadm -m iface' (cwd None) Thread-4103::DEBUG::2013-09-23 17:39:48,830::iscsiadm::91::Storage.Misc.excCmd::(_runCmd) SUCCESS: <err> = ''; <rc> = 0 Thread-4103::ERROR::2013-09-23 17:39:48,830::hsm::2987::Storage.HSM::(discoverSendTargets) Discovery failed Traceback (most recent call last): File "/usr/share/vdsm/storage/hsm.py", line 2985, in discoverSendTargets targets = iscsi.discoverSendTargets(iface, portal, cred) File "/usr/share/vdsm/storage/iscsi.py", line 223, in discoverSendTargets addIscsiPortal(iface, portal, credentials) File "/usr/share/vdsm/storage/iscsi.py", line 184, in addIscsiPortal iscsiadm.discoverydb_new(discoverType, iface.name, portalStr) File "/usr/share/vdsm/storage/iscsiadm.py", line 176, in discoverydb_new raise IscsiDiscoverdbError(rc, out, err) IscsiDiscoverdbError: (6, [], ['iscsiadm: Could not make dir /var/lib/iscsi/send_targets/192.168.24.200,3260 err 13', '', 'iscsiadm: Could not open /var/lib/iscsi/send_targets/192.168.24.200,3260: Permission denied', '', 'iscsiadm: Could not add new discovery record.']) Thread-4103::ERROR::2013-09-23 17:39:48,830::task::850::TaskManager.Task::(_setError) Task=`f49e993b-745c-4c91-800c-290331028bad`::Unexpected error Traceback (most recent call last): File "/usr/share/vdsm/storage/task.py", line 857, in _run return fn(*args, **kargs) File "/usr/share/vdsm/logUtils.py", line 45, in wrapper res = f(*args, **kwargs) File "/usr/share/vdsm/storage/hsm.py", line 2988, in discoverSendTargets raise se.iSCSIDiscoveryError(portal, e) iSCSIDiscoveryError: Failed discovery of iSCSI targets: "portal=IscsiPortal(hostname='192.168.24.200', port=3260), err=(6, [], ['iscsiadm: Could not make dir /var/lib/iscsi/send_targets/192.168.24.200,3260 err 13', '', 'iscsiadm: Could not open /var/lib/iscsi/send_targets/192.168.24.200,3260: Permission denied', '', 'iscsiadm: Could not add new discovery record.'])" Thread-4103::DEBUG::2013-09-23 17:39:48,831::task::869::TaskManager.Task::(_run) Task=`f49e993b-745c-4c91-800c-290331028bad`::Task._run: f49e993b-745c-4c91-800c-290331028bad ({'connection': '192.168.24.200', 'password': '', 'port': '3260', 'user': ''},) {} failed - stopping task Thread-4103::DEBUG::2013-09-23 17:39:48,831::task::1194::TaskManager.Task::(stop) Task=`f49e993b-745c-4c91-800c-290331028bad`::stopping in state preparing (force False) Thread-4103::DEBUG::2013-09-23 17:39:48,832::task::974::TaskManager.Task::(_decref) Task=`f49e993b-745c-4c91-800c-290331028bad`::ref 1 aborting True Thread-4103::INFO::2013-09-23 17:39:48,832::task::1151::TaskManager.Task::(prepare) Task=`f49e993b-745c-4c91-800c-290331028bad`::aborting: Task is aborted: 'Failed discovery of iSCSI targets' - code 475 Thread-4103::DEBUG::2013-09-23 17:39:48,832::task::1156::TaskManager.Task::(prepare) Task=`f49e993b-745c-4c91-800c-290331028bad`::Prepare: aborted: Failed discovery of iSCSI targets Thread-4103::DEBUG::2013-09-23 17:39:48,832::task::974::TaskManager.Task::(_decref) Task=`f49e993b-745c-4c91-800c-290331028bad`::ref 0 aborting True Thread-4103::DEBUG::2013-09-23 17:39:48,833::task::909::TaskManager.Task::(_doAbort) Task=`f49e993b-745c-4c91-800c-290331028bad`::Task._doAbort: force False Thread-4103::DEBUG::2013-09-23 17:39:48,833::resourceManager::976::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-4103::DEBUG::2013-09-23 17:39:48,833::task::579::TaskManager.Task::(_updateState) Task=`f49e993b-745c-4c91-800c-290331028bad`::moving from state preparing -> state aborting Thread-4103::DEBUG::2013-09-23 17:39:48,833::task::534::TaskManager.Task::(__state_aborting) Task=`f49e993b-745c-4c91-800c-290331028bad`::_aborting: recover policy none Thread-4103::DEBUG::2013-09-23 17:39:48,834::task::579::TaskManager.Task::(_updateState) Task=`f49e993b-745c-4c91-800c-290331028bad`::moving from state aborting -> state failed Thread-4103::DEBUG::2013-09-23 17:39:48,834::resourceManager::939::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-4103::DEBUG::2013-09-23 17:39:48,834::resourceManager::976::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-4103::ERROR::2013-09-23 17:39:48,834::dispatcher::67::Storage.Dispatcher.Protect::(run) {'status': {'message': 'Failed discovery of iSCSI targets: "portal=IscsiPortal(hostname=\'192.168.24.200\', port=3260), err=(6, [], [\'iscsiadm: Could not make dir /var/lib/iscsi/send_targets/192.168.24.200,3260 err 13\', \'\', \'iscsiadm: Could not open /var/lib/iscsi/send_targets/192.168.24.200,3260: Permission denied\', \'\', \'iscsiadm: Could not add new discovery record.\'])"', 'code': 475}} The engine is running in a virtual machine in a separate KVM host outside ovirt. The node it running (naturally) on a physical machine. Everything have been just been (re)installed. I have three nodes whereas two had previously been used as 2.3 nodes. I did however used the "reinstall" method that seem to repartition and reformat the local disk. Furthermore, when running into trouble just to be sure there where no leftovers I also scraped one of the nodes disk with dd and reinstalled it. Made no difference.. Part from the necessary configuration during install I have not really touched anything configuration wise. Also, just to let you know there is nothing wrong with the target nor the communication, I am able to just fine run the discovery and set up the iscsi session manually and the luns become accessible to the node. I even tried to the exact command that from the vdsm.log seem to be executed, that as well works just fine if executed manually. [root@bagaren vdsm]# /usr/bin/sudo -n /sbin/iscsiadm -m discoverydb -t sendtargets -I default -p 192.168.24.200:3260 --op=new New discovery record for [192.168.24.200,3260] added. The engine is running on top of Fedora 19 and the nodes where installed with the following iso: ovirt-node-iso-3.0.1-1.0.2.vdsm.fc19.iso