Bug 1306333

Summary: listAllDevices returns invalid parents in scsi_target devices
Product: Red Hat Enterprise Linux 7 Reporter: Martin Polednik <mpoledni>
Component: libvirtAssignee: John Ferlan <jferlan>
Status: CLOSED WONTFIX QA Contact: Virtualization Bugs <virt-bugs>
Severity: high Docs Contact:
Priority: unspecified    
Version: 7.2CC: alkaplan, dyuan, jferlan, jsuchane, mburman, michal.skrivanek, mpoledni, rbalakri, rbian, yisun
Target Milestone: rcKeywords: Reopened
Target Release: ---   
Hardware: x86_64   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2016-07-12 13:54:51 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:    
Bug Blocks: 1315100    
Attachments:
Description Flags
output of mentioned script on affected machine
none
nodedev-list
none
lspci
none
rhev device tree built on the host
none
libvirtd and vdsm logs
none
engine and virsh output none

Description Martin Polednik 2016-02-10 15:33:32 UTC
Created attachment 1122826 [details]
output of mentioned script on affected machine

Description of problem:
Node device list returned by python API listAllDevices (virConnectListAllNodeDevices) sometimes contains devices, whose parent does not exist. We have seen this with scsi_target devices.

Version-Release number of selected component (if applicable):
libvirt-1.2.17-13.el7_2.2

How reproducible:
Specific machines, 100%

Steps to Reproduce:
1. run following script to display XMLs of all devices:
import libvirt
 
c = libvirt.openReadOnly()
for dev in c.listAllDevices():
        print dev.XMLDesc()

Actual results:
Some scsi_target devices will contain parent (scsi_host) that is not found in the list.

Expected results:
Returned devices should be consistent.

Additional info:
This is problem for RHEV as we build a device tree in database, where having an existing parent is one of database constraints. We mostly need to know if this is a bug and parents of these devices should exist somewhere in the tree or if such usage is wrong.

Comment 1 Martin Polednik 2016-02-10 15:34:01 UTC
Created attachment 1122827 [details]
nodedev-list

Comment 2 Martin Polednik 2016-02-10 15:34:28 UTC
Created attachment 1122829 [details]
lspci

Comment 3 Martin Polednik 2016-02-10 15:35:08 UTC
Created attachment 1122830 [details]
rhev device tree built on the host

Comment 5 Martin Polednik 2016-02-29 13:15:53 UTC
Also, restarting libvirt clears these devices and can be considered workaround for any software that tries to build the device tree.

Comment 6 John Ferlan 2016-03-09 14:30:27 UTC
NOTE: If I 'massage' the python output a bit further, then there is no difference between the virsh and python output. The one thing virsh does that the libvirt-python doesn't do is sort the returned data on the <device> <name> field. Doing the same for the python output provided, I get the same list of data. 

What may be interesting is to see what 'virsh nodedev-list --tree' shows for the 'scsi_host14' through 'scsi_host23' at least with respect to the 'parent'.

You can also see what virsh has for XML by using virsh nodedev-dumpxml scsi_target14_0_0  (or whichever of those targets).

In the long run though, for 'udev' the parent is filled in by a call to udev_device_get_parent (in udevSetParent() in node_device_udev.c) and for 'hal' the parent is filled in by the attribute "info.parent" (in dev_create() in node_device_hal.c). So libvirt is only filling in the data that it gets from the subsystem.  I'll focus on udev since that's what's newer...

The reason why restarting libvirt would appear to clear things is that the device tree is rebuilt. Over time though, as devices are created, changed, or removed the libvirt node device driver is notified and will add/change/remove devices that based on udev/hal event callbacks. So "something" is creating the device and libvirt is just recognizing it. The problem then would be if that same "something" isn't removing the device and thus it appears to stick around. That could mean one of two things - "something" deletes the path, but doesn't tell the udev/hal subsystem or libvirt is missing the "remove" event.  Debugging that would require setting up usage of a debug libvirt environment (e.g. /etc/libvirt/libvirtd.conf changes to get debug messages from at least the node_device subsystem by setting 'log_level', 'log_filters', and 'log_outputs').

Focusing more on those problematic target14_0_0 through target23_0_0 devices. It seems those are related to the iSCSI subsystem (I use iSCSI on my host, so I see a similar <path> construct of "/sys/devices/platform/host*/session*"). However, in my case, the <parent>scsi_host# does exist (from the output of a virsh nodedev-dumpxml scsi_target#_0_0).  In fact the "/sys/class/scsi_host/host*/device/session*" values also match (another way to find things is via /sys/class/scsi_host... tree).

In any case, for me things are working just fine. Of course I'm using a different OS (f23), upstream libvirt, and libiscsi (1.15.0-1). Perhaps there's something fixed in the libiscsi subsystem. I don't follow it that closely.

Still first things first - let's see in your environment if the infrastructure exists (e.g. the /sys/devices/platform/... or /sys/class/scsi_host/... paths) for those devices.  For example from the python output:

<device>
  <name>scsi_target14_0_0</name>
  <path>/sys/devices/platform/host14/session3/target14:0:0</path>
  <parent>scsi_host14</parent>
  <capability type='scsi_target'>
    <target>target14:0:0</target>
  </capability>
</device>

Does that <path> exist? Does "/sys/devices/platform/host14/scsi_host" exist? And I assume if it does there's a single "host14" subdirectory? Next, does /sys/class/scsi_host/host14 exist? I would further assume an 'ls -al' would indicate that it's a link to the devices/platform/... tree.

Now, if none of that exists, then setting up debugging to "see" if a remove event is missed/lost would be the next challenge.

Comment 7 yisun 2016-03-23 09:54:04 UTC
not reproducible in qe's env either
per comment 6, set needinfo to Martin. 
And could you pls provide a machine which can reproduce this issue in a private comment? thx

Comment 8 Martin Polednik 2016-04-04 11:20:12 UTC
Can't really reproduce it again, possibly fixed in the process. Will update if I see some machine with reproducer.

Comment 10 John Ferlan 2016-04-25 12:18:33 UTC
I'm going to close as worksforme.  If it shows up again, the feel free to reopen and please be sure to provide extra data as shown in comment 6

Comment 11 Alona Kaplan 2016-05-16 06:41:30 UTC
This reproduces repeatedly on mburman's lynx15.qa.lab.tlv.redhat.com
Burman, can you supply the information requested in the (long) comment 6?

Comment 12 Alona Kaplan 2016-05-16 06:41:51 UTC
*** Bug 1334633 has been marked as a duplicate of this bug. ***

Comment 13 Michael Burman 2016-05-16 06:52:07 UTC
[root@lynx15 ~]# cat /sys/devices/platform/
alarmtimer/       dcdbas/           host83/           ipmi_bmc.008b.32/ pcspkr/           serial8250/       
coretemp.0/       Fixed MDIO bus.0/ host85/           microcode/        power/            uevent 

[root@lynx15 ~]# cat /sys/devices/platform/host83/session78/target83\:0\:0/
83:0:0:0/  83:0:0:1/  83:0:0:2/  83:0:0:3/  83:0:0:4/  83:0:0:5/  power/     subsystem/ uevent


[root@lynx15 ~]# cat /sys/devices/platform/host85/scsi_host/host85/

[root@lynx15 ~]# cat /sys/class/scsi_host/host85/

Note, this is not my HW, please contact me in privet or ncredy for further investigation, thanks

Comment 14 John Ferlan 2016-05-17 12:02:28 UTC
Right now I'm in the middle of other work, so in order to "save" the state, can you provide more information here vis-a-vis the details of what was asked for in comment 6? What's shown helps a little, but it's not complete. You will have to extrapolate to the environment causing the problem. Specifically:

"What may be interesting is to see what 'virsh nodedev-list --tree' shows for the 'scsi_host14' through 'scsi_host23' at least with respect to the 'parent'.

You can also see what virsh has for XML by using virsh nodedev-dumpxml scsi_target14_0_0  (or whichever of those targets)."

(although in this case it seems host85 is the target and there's no state under host85, but yet it shows up in output... )

It would also be beneficial to provide details such as OS version, libvirt version...  anything else configured on the system (iSCSI) that may be generating host devices?  It's noted that it's reproducible, but not how it's reproducible. Is this a stress test or just normal usage? What seems to trigger things? I can debug libvirt problems, but using RHEV is not in my wheelhouse. So if you have a sequence that can make it so the device doesn't exist, something is done, and then the device exists but with no parent, then run libvirtd with debugging enabled, grab/save the log output and then provide that - it would allow me to dig into that data. Without that, it'll be hard to replicate the environment and conditions in order to have a chance at resolving.

Comment 15 Michael Burman 2016-05-17 12:22:39 UTC
Hi John,

I can't provide all this details, it's an production environment that is running all the time(infra)and it's not mine. 

What we can do is to talk online(tomorrow for example), i will get access to this environment, you as well. We will reproduce it(it's 100 reproducible) and you will debug it in real time and pick all the relevant and desired info. 
Is that something that can work for you? this is the time to investigate it and not to 'save' the state of it. It shouldn't take to long. 
We can talk on chat or via e-mail, thanks)

Comment 16 Michael Burman 2016-05-18 12:00:36 UTC
This is reproduced on --> 

libvirt-1.2.17-13.el7_2.4.x86_64
qemu-kvm-rhev-2.3.0-31.el7_2.13.x86_64
vdsm-4.17.28-0.el7ev.noarch
3.10.0-327.18.2.el7.x86_64
Red Hat Enterprise Linux Server release 7.2 (Maipo)

- Attaching libvirtd log in debug mode, vdsm log and supervdsm log.
As well the engine and server logs from engine. 
- The output of virsh -r nodedev-list --tree
I don't see there a scsi_host## that is missing the parent(but maybe i missed it, it's why i asked you to log in)


[root@lynx15 ~]# virsh -V
Virsh command line tool of libvirt 1.2.17
See web site at http://libvirt.org/

Compiled with support for:
 Hypervisors: QEMU/KVM LXC ESX Test
 Networking: Remote Network Bridging Interface netcf Nwfilter VirtualPort
 Storage: Dir Disk Filesystem SCSI Multipath iSCSI LVM RBD Gluster
 Miscellaneous: Daemon Nodedev SELinux Secrets Debug DTrace Readline Modular


[root@lynx15 ~]# yum list installed | grep iscsi
iscsi-initiator-utils.x86_64      6.2.0.873-33.el7_2.1     @latest_rhel_z_stream
iscsi-initiator-utils-iscsiuio.x86_64
libiscsi.x86_64                   1.9.0-6.el7              @rhel-7.2

Comment 17 Michael Burman 2016-05-18 12:06:21 UTC
Created attachment 1158768 [details]
libvirtd and vdsm logs

Comment 18 Michael Burman 2016-05-18 12:10:23 UTC
Created attachment 1158769 [details]
engine and virsh output

Comment 19 John Ferlan 2016-06-27 22:13:20 UTC
Finally got some time to look at this... Started generating a response and "poof" away went my editing window because of a mistakenly typed ctrl-w (dang browser software)...

Anyway, what I've deduced from the output shown is I don't believe you've replicated the original problem.  You'll note that the original problem lists "scsi_target14_0_0" through "scsi_target23_0_0" with <parent> fields that list 'scsi_host14' through 'scsi_host23'; however, those scsi_host##'s don't exist. That output is also show in some nodedev-list output

The output you've generated doesn't have that, but it does have some interesting tidbits.

Comparing the output in libvirtd.log and engine.log I found json type output in the engine.log at timestamp "2016-05-18 14:28:48,185 INFO" where if you edit the file and search on "scsi_host8" you'll see scsi_host87 and scsi_host89 listed; however, searching the libvirtd.log output around the same period shows a fetch of scsi_host's, but only for scsi_host0 through scsi_host5.

However, way back at the beginning of libvirtd.log there's remnants of a udev callback to 'remove' the 'scsi_host89' and 'scsi_host87' (at "2016-05-18 11:19:25.954" and "2016-05-18 11:19:25.896").  So as far as libvirt is concerned they were deleted, but that "[org.ovirt.engine.core.vdsbroker.HostDevListByCapsVDSCommand] (ajp-/127.0.0.1:8702-5) [4947bee4] FINISH, HostDevListByCapsVDSCommand" still listed them.

That hints to me that perhaps there's a "cache" being kept by something else that isn't updating the scsi_host list... Which is perhaps a different problem, but not a libvirt problem.

In order to reproduce the original scenario the scsi_target## devices have to be listed in libvirt output with no corresponding similarly name scsi_host## device (e.g scsi_target87 should have scsi_host87).

Comment 20 Michal Skrivanek 2016-07-07 07:02:38 UTC
I don't think we keep any cache in vdsm(right, Martin?), would it be possible it is cached on libvirt side instead?

Comment 21 Michal Skrivanek 2016-07-08 07:21:59 UTC
John,
I can see in the same libvirt log that despite scsi_host89 was removed, scsi_target89_0_0 is still being reported. The code in vdsm querying it from libvirt is not caching anything and is always querying libvirt directly, so I'm assuming the wrong parent was indeed returned by libvirt for that scsi_target89_0_0 device

Comment 22 John Ferlan 2016-07-11 19:20:03 UTC
Not sure I have an answer for scsi_target87_0_0 and scsi_target89_0_0 (although perhaps notable that 88 isn't there).  In the long run, libvirt only reports what it gets from udev. If udev has the target there, but no host - that could either be a bug in udev or perhaps that those two LUNs still have outstanding I/O on them so UDEV won't delete them. I don't have that kind of knowledge of that area.

The libvirt nodedev driver reacts to add, change, and delete events from udevEventHandleCallback. So as soon as udev tells us, we handle it appropriately.

Addition and Deletion from libvirt lists is not cached in any overt way that I can see.

Still, getting a parent is not "guaranteed" to return something as the API indicates:

http://libvirt.org/html/libvirt-libvirt-nodedev.html#virNodeDeviceGetParent

"Returns
the name of the device's parent, or NULL if an error occurred or when the device has no parent."

Comment 23 Michal Skrivanek 2016-07-12 13:54:51 UTC
(In reply to John Ferlan from comment #22)
> Not sure I have an answer for scsi_target87_0_0 and scsi_target89_0_0
> (although perhaps notable that 88 isn't there).  In the long run, libvirt
> only reports what it gets from udev. If udev has the target there, but no
> host - that could either be a bug in udev or perhaps that those two LUNs
> still have outstanding I/O on them so UDEV won't delete them. I don't have
> that kind of knowledge of that area.

yeah, I wouldn't be surprised if that's the reason

> 
> The libvirt nodedev driver reacts to add, change, and delete events from
> udevEventHandleCallback. So as soon as udev tells us, we handle it
> appropriately.
> 
> Addition and Deletion from libvirt lists is not cached in any overt way that
> I can see.
> 
> Still, getting a parent is not "guaranteed" to return something as the API
> indicates:
> 
> http://libvirt.org/html/libvirt-libvirt-nodedev.html#virNodeDeviceGetParent
> 
> "Returns
> the name of the device's parent, or NULL if an error occurred or when the
> device has no parent."

that's ok, but here we're talking of a parent which is not reported. Alright, we'll handle both cases internally, dropping the devices if they do not have a parent assuming there was some kind of an error or they are stuck/being removed