illumos gate

SmartOS user Smithx10 reported several instances suffering from wedged RX virtqueues when running under bhyve (with viona driving the virtio-net emulation).
One guest in question, running Linux 4.14.35-1902.302.2.el7uek.x86_64 reported this error via dmesg:

[251475.388441] virtio_net virtio4: input.0:id 282 is not a head!

The state for the viona ring associated with that virtqueue was collected:

{
    vr_link = 0xfffffd6af396c600
    vr_lock = {
        _opaque = [ 0 ]
    }
    vr_cv = {
        _opaque = 0x1
    }
    vr_state = 0x3
    vr_state_flags = 0
    vr_xfer_outstanding = 0
    vr_worker_thread = 0xfffffd6663ccc4a0
    vr_lease = 0xfffffd6ad4720528
    vr_txdesb = 0
    vr_txiov = 0
    vr_intr_enabled = 0
    vr_msi_addr = 0xfee00000
    vr_msi_msg = 0x40a1
    vr_a_mutex = {
        _opaque = [ 0 ]
    }
    vr_u_mutex = {
        _opaque = [ 0 ]
    }
    vr_pa = 0x136f20000
    vr_size = 0x400
    vr_mask = 0x3ff
    vr_cur_aidx = 0x90fd
    vr_cur_uidx = 0x90fd
    vr_map_pages = 0xfffffd6ad585bc80
    vr_stats = {
        rs_ndesc_too_high = 0
        rs_bad_idx = 0
        rs_indir_bad_len = 0
        rs_indir_bad_nest = 0
        rs_indir_bad_next = 0
        rs_no_space = 0xf9f53
        rs_too_many_desc = 0
        rs_desc_bad_len = 0
        rs_bad_ring_addr = 0
        rs_fail_hcksum = 0
        rs_fail_hcksum6 = 0
        rs_fail_hcksum_proto = 0
        rs_bad_rx_frame = 0
        rs_rx_merge_overrun = 0
        rs_rx_merge_underrun = 0
        rs_rx_pad_short = 0x32
        rs_rx_mcast_check = 0
        rs_too_short = 0
        rs_tx_absent = 0
        rs_rx_hookdrop = 0
        rs_tx_hookdrop = 0
    }
}

We can see the rs_no_space count is high, and if examined live, still climbing. The guest kernel would have stopped placing available buffers in that virtqueue after deciding it was in an erroneous state. As such, our failure to deliver packets makes sense in context. I dumped the guest memory pages holding the virtqueue for further inspection (attached as virtqueue.bin).
These macros (customized for how the VQ is sized) allow for easy inspection with mdb:

::typedef -c LP64
::typedef 'struct { uint64_t addr; uint32_t len; uint16_t flags; uint16_t next; }' virtio_desc_t
::typedef 'struct { uint16_t flags; uint16_t idx; uint16_t ent[0x400]; uint16_t last_avail_idx; uint8_t _pad[0x7fa]; }' virtio_avail_t
::typedef 'struct { uint32_t idx; uint32_t len; }' virtio_used_ent_t
::typedef 'struct { uint16_t flags; uint16_t idx; virtio_used_ent_t ent[0x400]; uint16_t last_used_idx;}' virtio_used_t
::typedef 'struct { virtio_desc_t desc[0x400]; virtio_avail_t avail; virtio_used_t used; }' virtio_queue_t

First, let's figure out what the error message from Linux means. Using the v4.14 sources as a rough guide, we see that message emitted from virtqueue_get_buf_ctx:

        /* Only get used array entries after they have been exposed by host. */
        virtio_rmb(vq->weak_barriers);

        last_used = (vq->last_used_idx & (vq->vring.num - 1));
        i = virtio32_to_cpu(_vq->vdev, vq->vring.used->ring[last_used].id);
        *len = virtio32_to_cpu(_vq->vdev, vq->vring.used->ring[last_used].len);

        if (unlikely(i >= vq->vring.num)) {
                BAD_RING(vq, "id %u out of range\n", i);
                return NULL;
        }
        if (unlikely(!vq->desc_state[i].data)) {
                BAD_RING(vq, "id %u is not a head!\n", i);
                return NULL;
        }

So it read what it expected to be the next descriptor from the "used" side of the virtqueue and found no in-kernel data associated with it. Fortunately for us, when that is working properly (as opposed to emitting the aforementioned error), the function records the index of the successfully-retrieved descriptor:

        if (!(vq->avail_flags_shadow & VRING_AVAIL_F_NO_INTERRUPT))
                virtio_store_mb(vq->weak_barriers,
                                &vring_used_event(&vq->vring),
                                cpu_to_virtio16(_vq->vdev, vq->last_used_idx));

Let's start from there when examining the ring contents:

> 0::print virtio_queue_t avail.last_avail_idx
avail.last_avail_idx = 0x8ef6

The viona host state for the ring indicated it had progressed as far as 0x90fd before finding no more entries in the ring, a difference of 519 entries - well below the ring size of 1024. This makes sense, as the guest may not have kept the avail ring 100% populated with new buffers to fill.
Let's inspect the used entries around that index (8ef6 masked for a ring size of 0x400 :

... Masked for the ring size of 0x400 ...
> 8ef6&3ff=K
                2f6
> 0::print -ta virtio_queue_t used.ent[2f6]
67b4 virtio_used_ent_t used.ent[2f6] = {
    67b4 uint32_t used.ent[2f6].idx = 0x11a
    67b8 uint32_t used.ent[2f6].len = 0x4e
}
> 11a=E
                282

So that entry does match the error message emitted.
Let's take a look at the surrounding entries in the ring for context. Presumably those preceding 0x11a were fine.

> 679c,6::print -ta virtio_used_ent_t
679c virtio_used_ent_t {
    679c uint32_t idx = 0x130
    67a0 uint32_t len = 0x56
}
67a4 virtio_used_ent_t {
    67a4 uint32_t idx = 0x12f
    67a8 uint32_t len = 0xa9
}
67ac virtio_used_ent_t {
    67ac uint32_t idx = 0x11d
    67b0 uint32_t len = 0x542
}
67b4 virtio_used_ent_t {
    67b4 uint32_t idx = 0x11a
    67b8 uint32_t len = 0x4e
}
67bc virtio_used_ent_t {
    67bc uint32_t idx = 0x114
    67c0 uint32_t len = 0x4e
}
67c4 virtio_used_ent_t {
    67c4 uint32_t idx = 0x11c
    67c8 uint32_t len = 0x4e
}

And now let's look for similar entries in the avail ring, as they would have been presented to the device to be populated with packets:

> 0::print -ta virtio_queue_t avail.ent
4004 uint16_t [1024] avail.ent = [ 0x385, 0x384, 0x383, 0x382, 0x3a2, 0x3a1, 0x3a0, 0x39f, 0x39e, 0x39d, 0x39c, 0x391, 0x390, 0x38f, 0x38e, 0x38d, 0x38c, 0x3ae, 0x3db, 0x3e2, 0x3e1, 0x3ad, 0x3d5, 0x3af, 0x3c7, 0x3bf, 0x37c, 0x37b, 0x37a, 0x379, 0x378, 0x377, ... ]
> 4004,400/axn ! grep 11a
0x411a:         2fd
0x4204:         11a
> (4204-4004)%2=K
                100
> 0::print -ta virtio_queue_t avail.ent[100]
4204 uint16_t avail.ent[100] = 0x11a
> 4204-c,8/axn
0x41f8:         0x41f8:         2ba
0x41fa:         2be
0x41fc:         2c0
0x41fe:         11b
0x4200:         11c
0x4202:         114
0x4204:         11a
0x4206:         128

There appears to be some difference in the order that viona consumed these available buffers to send packets to the guest, but that should be fine. Per the spec:

Device is not generally required to use buffers in the same order in which they have been made available by the driver.

That said, further investigation is required to see why those are so out of order, and if the state in the ring matches all expectations.