Re: [Qemu-discuss] How to resolve "Failed to mmap" error?

[Alex Williamson]

On Thu, 6 Oct 2016 23:19:13 -0700
A223 A223 <address@hidden> wrote:

> On Thu, Oct 6, 2016 at 9:29 PM, Alex Williamson
> <address@hidden> wrote:
> > On Thu, 6 Oct 2016 21:07:06 -0700
> > A223 A223 <address@hidden> wrote:
> >  
> >> On Thu, Oct 6, 2016 at 8:30 PM, A223 A223 <address@hidden> wrote:  
> >> > On Thu, Oct 6, 2016 at 9:46 AM, Alex Williamson
> >> > <address@hidden> wrote:  
> >> >> On Wed, 5 Oct 2016 20:30:34 -0700
> >> >> A223 A223 <address@hidden> wrote:
> >> >>  
> >> >>> On Wed, Oct 5, 2016 at 9:33 AM, Alex Williamson
> >> >>> <address@hidden> wrote:  
> >> >>> > On Wed, 5 Oct 2016 02:13:21 -0700
> >> >>> > A223 A223 <address@hidden> wrote:  
> >> >>> >> How can I go about tracking down the root cause of this error?  
> >> >>> >
> >> >>> > This often means that the device resources are in use by another,
> >> >>> > non-pci driver.  Look in /proc/iomem and /proc/ioport to see if any
> >> >>> > drivers are claiming sub-regions on the device.  You can also turn on
> >> >>> > tracing and look for the event vfio_region_mmap_fault, which might 
> >> >>> > give
> >> >>> > us more information (see docs/tracing.txt).  Also, please provide 
> >> >>> > 'sudo
> >> >>> > lspci -vvvs 5:00.0' so we can see the device resources.  Thanks,  
> >> >>>
> >> >>> The simpletrace output wouldn't parse for me using the python script
> >> >>> (I'll paste the trace at the end of this email), so I used the ftrace
> >> >>> backend instead (
> >> >>> https://drive.google.com/open?id=0Bwjufq6oAZMfMVpUYTUxODR0NW8 ). It's
> >> >>> quite large and I'm not sure what I'm looking for, so I didn't look at
> >> >>> it very carefully.  
> >> >>
> >> >> That's not the right trace, that's like kvm trace or something.  Try:
> >> >>
> >> >> # ./configure --enable-trace-backends=log
> >> >>
> >> >> # echo vfio_region_mmap_fault > events.txt
> >> >>
> >> >> Then add to your qemu commandline "-trace events=events.txt".  You
> >> >> should get maybe a couple extra log lines per boot, not gobs of output. 
> >> >>  
> >> >
> >> > Ah, got it. Here are the relevant log lines then:
> >> >
> >> > address@hidden:vfio_region_mmap_fault Region 0000:05:00.0 BAR
> >> > 2 mmaps[0], [20000000000 - 1ffffffffff], fault: -22
> >> > qemu-system-x86_64: -device
> >> > vfio-pci,host=05:00.0,bus=root.1,addr=00.5: Failed to mmap
> >> > 0000:05:00.0 BAR 2. Performance may be slow  
> >>
> >> I took a look at everything again and noted this in the lspci output
> >> for the Fresco Logic USB controller:
> >> Vector table: BAR=2 offset=00000000
> >> PBA: BAR=4 offset=00000000
> >>
> >> Is it normal for both the Vector table and PBA to have a 0 offset?  
> >
> > Note that they're in different BARs, so it's a little unexpected but
> > it's not wrong.  The MSI-X table does appear to be the problem though.
> > Based on that trace line, the region size we're trying to mmap is
> > zero.  We're probably hitting a corner case of a page sized BAR
> > containing the MSI-X table, where we cannot mmap the page covering the
> > table.  We need to figure out where that's coming from.  Please add the
> > additional trace lines to your events.txt and try again:
> >
> > vfio_region_sparse_mmap_header
> > vfio_region_sparse_mmap_entry
> > vfio_region_setup
> > vfio_msix_fixup
> >
> > The bad news is that due to the MSI-X table, we're not going to be able
> > to mmap that BAR, the good news is that it probably doesn't actually
> > hurt performance.  With the table and PBA in separate BARs, my guess
> > would be that's the only thing in those BARs.  Thanks,  
> 
> Ah, overall bad news for me, as I now have absolutely no clue what's
> causing my USB performance/reliability issues in the VM :(
> 
> Nonetheless, here is the new log output:
> 
> address@hidden:vfio_region_setup Device 0000:02:00.0, region 0
> "0000:02:00.0 BAR 0", flags: 7, offset: 0, size: 1000000
> address@hidden:vfio_region_setup Device 0000:02:00.0, region 1
> "0000:02:00.0 BAR 1", flags: 7, offset: 10000000000, size: 10000000
> address@hidden:vfio_region_setup Device 0000:02:00.0, region 2
> "0000:02:00.0 BAR 2", flags: 0, offset: 20000000000, size: 0
> address@hidden:vfio_region_setup Device 0000:02:00.0, region 3
> "0000:02:00.0 BAR 3", flags: 7, offset: 30000000000, size: 2000000
> address@hidden:vfio_region_setup Device 0000:02:00.0, region 4
> "0000:02:00.0 BAR 4", flags: 0, offset: 40000000000, size: 0
> address@hidden:vfio_region_setup Device 0000:02:00.0, region 5
> "0000:02:00.0 BAR 5", flags: 3, offset: 50000000000, size: 80
> address@hidden:vfio_region_setup Device 0000:02:00.1, region 0
> "0000:02:00.1 BAR 0", flags: 7, offset: 0, size: 4000
> address@hidden:vfio_region_setup Device 0000:02:00.1, region 1
> "0000:02:00.1 BAR 1", flags: 0, offset: 10000000000, size: 0
> address@hidden:vfio_region_setup Device 0000:02:00.1, region 2
> "0000:02:00.1 BAR 2", flags: 0, offset: 20000000000, size: 0
> address@hidden:vfio_region_setup Device 0000:02:00.1, region 3
> "0000:02:00.1 BAR 3", flags: 0, offset: 30000000000, size: 0
> address@hidden:vfio_region_setup Device 0000:02:00.1, region 4
> "0000:02:00.1 BAR 4", flags: 0, offset: 40000000000, size: 0
> address@hidden:vfio_region_setup Device 0000:02:00.1, region 5
> "0000:02:00.1 BAR 5", flags: 0, offset: 50000000000, size: 0
> address@hidden:vfio_region_setup Device 0000:05:00.0, region 0
> "0000:05:00.0 BAR 0", flags: 7, offset: 0, size: 10000
> address@hidden:vfio_region_setup Device 0000:05:00.0, region 1
> "0000:05:00.0 BAR 1", flags: 0, offset: 10000000000, size: 0
> address@hidden:vfio_region_sparse_mmap_header Device
> 0000:05:00.0 region 2: 1 sparse mmap entries
> address@hidden:vfio_region_sparse_mmap_entry sparse entry 0 [0x0 - 0x0]
> address@hidden:vfio_region_setup Device 0000:05:00.0, region 2
> "0000:05:00.0 BAR 2", flags: f, offset: 20000000000, size: 1000
> address@hidden:vfio_region_setup Device 0000:05:00.0, region 3
> "0000:05:00.0 BAR 3", flags: 0, offset: 30000000000, size: 0
> address@hidden:vfio_region_setup Device 0000:05:00.0, region 4
> "0000:05:00.0 BAR 4", flags: 7, offset: 40000000000, size: 1000
> address@hidden:vfio_region_setup Device 0000:05:00.0, region 5
> "0000:05:00.0 BAR 5", flags: 0, offset: 50000000000, size: 0
> address@hidden:vfio_region_mmap_fault Region 0000:05:00.0 BAR
> 2 mmaps[0], [20000000000 - 1ffffffffff], fault: -22
> qemu-system-x86_64: -device
> vfio-pci,host=05:00.0,bus=root.1,addr=00.5: Failed to mmap
> 0000:05:00.0 BAR 2. Performance may be slow
> SeaBIOS (version rel-1.9.3-0-ge2fc41e-prebuilt.qemu-project.org)

Hi Andrew,

Would it be possible for you to test the patch below?  I'd be happy to
add Reported-by and Tested-by credits to the patch if you can provide
your real name (and preferred email if other than this one).  Thanks,

Alex

commit 4dcabf99c7d893e14171d01f1214b4ec0977fc28
Author: Alex Williamson <address@hidden>
Date:   Fri Oct 7 10:14:22 2016 -0600

    vfio: Handle zero-length sparse mmap ranges
    
    As reported in the link below, user has a PCI device with a 4KB BAR
    which contains the MSI-X table.  This seems to hit a corner case in
    the kernel where the region reports being mmap capable, but the sparse
    mmap information reports a zero sized range.  It's not entirely clear
    that the kernel is incorrect in doing this, but regardless, we need
    to handle it.  To do this, fill our mmap array only with non-zero
    sized sparse mmap entries and add an error return from the function
    so we can tell the difference between nr_mmaps being zero based on
    sparse mmap info vs lack of sparse mmap info.
    
    NB, this doesn't actually change the behavior of the device, it only
    removes the scary "Failed to mmap ... Performance may be slow" error
    message.  We cannot currently create an mmap over the MSI-X table.
    
    Link: 
http://lists.nongnu.org/archive/html/qemu-discuss/2016-10/msg00009.html
    Signed-off-by: Alex Williamson <address@hidden>

diff --git a/hw/vfio/common.c b/hw/vfio/common.c
index 9505fb3..ba8d451 100644
--- a/hw/vfio/common.c
+++ b/hw/vfio/common.c
@@ -610,16 +610,16 @@ vfio_get_region_info_cap(struct vfio_region_info *info, 
uint16_t id)
     return NULL;
 }
 
-static void vfio_setup_region_sparse_mmaps(VFIORegion *region,
-                                           struct vfio_region_info *info)
+static int vfio_setup_region_sparse_mmaps(VFIORegion *region,
+                                          struct vfio_region_info *info)
 {
     struct vfio_info_cap_header *hdr;
     struct vfio_region_info_cap_sparse_mmap *sparse;
-    int i;
+    int i, j;
 
     hdr = vfio_get_region_info_cap(info, VFIO_REGION_INFO_CAP_SPARSE_MMAP);
     if (!hdr) {
-        return;
+        return -ENODEV;
     }
 
     sparse = container_of(hdr, struct vfio_region_info_cap_sparse_mmap, 
header);
@@ -627,16 +627,24 @@ static void vfio_setup_region_sparse_mmaps(VFIORegion 
*region,
     trace_vfio_region_sparse_mmap_header(region->vbasedev->name,
                                          region->nr, sparse->nr_areas);
 
-    region->nr_mmaps = sparse->nr_areas;
-    region->mmaps = g_new0(VFIOMmap, region->nr_mmaps);
+    region->mmaps = g_new0(VFIOMmap, sparse->nr_areas);
 
-    for (i = 0; i < region->nr_mmaps; i++) {
-        region->mmaps[i].offset = sparse->areas[i].offset;
-        region->mmaps[i].size = sparse->areas[i].size;
-        trace_vfio_region_sparse_mmap_entry(i, region->mmaps[i].offset,
-                                            region->mmaps[i].offset +
-                                            region->mmaps[i].size);
+    for (i = 0, j = 0; i < sparse->nr_areas; i++) {
+        trace_vfio_region_sparse_mmap_entry(i, sparse->areas[i].offset,
+                                            sparse->areas[i].offset +
+                                            sparse->areas[i].size);
+
+       if (sparse->areas[i].size) {
+            region->mmaps[j].offset = sparse->areas[i].offset;
+            region->mmaps[j].size = sparse->areas[i].size;
+            j++;
+        }
     }
+
+    region->nr_mmaps = j;
+    region->mmaps = g_realloc(region->mmaps, j * sizeof(VFIOMmap));
+
+    return 0;
 }
 
 int vfio_region_setup(Object *obj, VFIODevice *vbasedev, VFIORegion *region,
@@ -665,9 +673,9 @@ int vfio_region_setup(Object *obj, VFIODevice *vbasedev, 
VFIORegion *region,
             region->flags & VFIO_REGION_INFO_FLAG_MMAP &&
             !(region->size & ~qemu_real_host_page_mask)) {
 
-            vfio_setup_region_sparse_mmaps(region, info);
+            ret = vfio_setup_region_sparse_mmaps(region, info);
 
-            if (!region->nr_mmaps) {
+            if (ret) {
                 region->nr_mmaps = 1;
                 region->mmaps = g_new0(VFIOMmap, region->nr_mmaps);
                 region->mmaps[0].offset = 0;