Date: Mon, 1 Aug 2016 18:47:40 +0300 From: Andriy Gapon <avg@FreeBSD.org> To: "freebsd-virtualization@freebsd.org" <freebsd-virtualization@FreeBSD.org> Subject: vtbd stuck i/o Message-ID: <d2c4f11d-20bb-0f6c-354a-1cb2a1ede9d9@FreeBSD.org>
next in thread | raw e-mail | index | archive | help
>From time to time I experience a problem where a FreeBSD guest which
runs in a bhyve VM and uses virtio-blk disks gets stuck waiting for a
disk I/O operation to complete.
I tried to analyze one instance of them problem and discovered the vtblk
in a state where there was one request (a flush) in vtblk_req_ready,
nothing in vtblk_bioq and one apparently completed but unprocessed
request in vtblk_vq (which I discoved by manually following the steps in
virtqueue_dequeue). It seemed like perhaps an interrupt was not
generated or lost somehow.
I will appreciate any help with either analyzing this problem or adding
some diagnostic code for future analysis.
It's not super easy to reproduce the problem, but it occurs once in a while.
Some data from my debugging session:
(kgdb) p *(struct vtblk_softc *)$26->d_drv1
$27 = {
vtblk_dev = 0xfffff800036a3000,
vtblk_mtx = {
lock_object = {
lo_name = 0xfffff800031f9440 "vtblk2",
lo_flags = 16973824,
lo_data = 0,
lo_witness = 0xfffffe0000b94d00
},
mtx_lock = 4
},
vtblk_features = 268437060,
vtblk_flags = 1,
vtblk_vq = 0xfffff80003899000,
vtblk_sglist = 0xfffff8000386a800,
vtblk_disk = 0xfffff800038ae400,
vtblk_bioq = {
queue = {
tqh_first = 0x0,
tqh_last = 0xfffff8000389d150
},
last_offset = 42949672960,
insert_point = 0x0
},
vtblk_req_free = {
tqh_first = 0xfffff8000387dac0,
tqh_last = 0xfffff8000387ea20
},
vtblk_req_ready = {
tqh_first = 0xfffff8000387db00,
tqh_last = 0xfffff8000387db20
},
vtblk_req_ordered = 0x0,
vtblk_max_nsegs = 35,
vtblk_request_count = 64,
vtblk_write_cache = VTBLK_CACHE_WRITEBACK,
vtblk_dump_queue = {
tqh_first = 0x0,
tqh_last = 0xfffff8000389d1a8
},
vtblk_dump_request = {
vbr_hdr = {
type = 0,
ioprio = 0,
sector = 0
},
vbr_bp = 0x0,
vbr_ack = 0 '\000',
vbr_link = {
tqe_next = 0x0,
tqe_prev = 0x0
}
}
}
(kgdb) p *$27.vtblk_vq
$30 = {
vq_dev = 0xfffff800036a3b00,
vq_name = "vtblk2 request", '\000' <repeats 17 times>,
vq_queue_index = 0,
vq_nentries = 64,
vq_flags = 1,
vq_alignment = 4096,
vq_ring_size = 8192,
vq_ring_mem = 0xfffffe003c687000,
vq_max_indirect_size = 35,
vq_indirect_mem_size = 560,
vq_intrhand = 0xffffffff80888d02 <vtblk_vq_intr>,
vq_intrhand_arg = 0xfffff8000389d100,
vq_ring = {
num = 64,
desc = 0xfffffe003c687000,
avail = 0xfffffe003c687400,
used = 0xfffffe003c688000
},
vq_free_cnt = 63,
vq_queued_cnt = 0,
vq_desc_head_idx = 2,
vq_used_cons_idx = 55297,
vq_descx = 0xfffff80003899080
}
(kgdb) p *$27.vtblk_req_ready.tqh_first
$34 = {
vbr_hdr = {
type = 2147483652,
ioprio = 1,
sector = 0
},
vbr_bp = 0xfffff800038d8d38,
vbr_ack = 255 '\377',
vbr_link = {
tqe_next = 0x0,
tqe_prev = 0xfffff8000389d180
}
}
(kgdb) p/x 2147483652
$35 = 0x80000004
(kgdb) p *$34.vbr_bp
$36 = {
bio_cmd = 5,
bio_flags = 8,
bio_cflags = 0,
bio_pflags = 0,
bio_dev = 0x0,
bio_disk = 0xfffff800038ae400,
bio_offset = 42949672960,
bio_bcount = 0,
bio_data = 0x0,
bio_ma = 0x0,
bio_ma_offset = 0,
bio_ma_n = 0,
bio_error = 0,
bio_resid = 0,
bio_done = 0xffffffff80949672 <g_disk_done>,
bio_driver1 = 0x0,
bio_driver2 = 0x0,
bio_caller1 = 0x0,
bio_caller2 = 0x0,
bio_queue = {
tqe_next = 0x0,
tqe_prev = 0xfffff8000389d150
},
...
bio_from = 0x0,
bio_to = 0x0,
bio_length = 0,
bio_completed = 0,
bio_children = 0,
bio_inbed = 0,
bio_parent = 0xfffff800081de8d0,
bio_t0 = {
sec = 23228,
frac = 3207008011652053160
},
bio_task = 0x0,
bio_task_arg = 0x0,
bio_classifier1 = 0x0,
bio_classifier2 = 0x0,
bio_pblkno = 0
}
(kgdb) p $50.vq_ring.used->idx
$51 = 55298
(kgdb) p *$50.vq_ring.used
$52 = {
flags = 0,
idx = 55298,
ring = 0xfffffe003c688004
}
(kgdb) p (55297 + 1) & 63
$53 = 2
(kgdb) p $50.vq_ring.used->ring[2]
$54 = {
id = 10,
len = 1
}
(kgdb) p $50.vq_descx[10]
$55 = {
cookie = 0xfffff8000387db80,
indirect = 0xfffff80003895400,
indirect_paddr = 59331584,
ndescs = 1
}
(kgdb) p *(struct vtblk_request *)$55.cookie
$57 = {
vbr_hdr = {
type = 1,
ioprio = 1,
sector = 32562128
},
vbr_bp = 0xfffff800061492f0,
vbr_ack = 0 '\000',
vbr_link = {
tqe_next = 0x0,
tqe_prev = 0x0
}
}
(kgdb) p *$57.vbr_bp
$58 = {
bio_cmd = 2,
bio_flags = 0,
bio_cflags = 0,
bio_pflags = 0,
bio_dev = 0x0,
bio_disk = 0xfffff800038ae400,
bio_offset = 16671809536,
bio_bcount = 90112,
bio_data = 0xfffffe001c268000 "",
bio_ma = 0x0,
bio_ma_offset = 0,
bio_ma_n = 0,
bio_error = 0,
bio_resid = 0,
bio_done = 0xffffffff80949672 <g_disk_done>,
bio_driver1 = 0x0,
bio_driver2 = 0x0,
bio_caller1 = 0x0,
bio_caller2 = 0x0,
bio_queue = {
tqe_next = 0x0,
tqe_prev = 0xfffff8000389d150
},
bio_attribute = 0x0,
bio_zone = {
...
},
bio_from = 0x0,
bio_to = 0x0,
bio_length = 90112,
bio_completed = 0,
bio_children = 0,
bio_inbed = 0,
bio_parent = 0xfffff80003b8b8d0,
bio_t0 = {
sec = 23228,
frac = 3190990625700496616
},
bio_task = 0x0,
bio_task_arg = 0x0,
bio_classifier1 = 0x0,
bio_classifier2 = 0x0,
bio_pblkno = 32562128
}
--
Andriy Gapon
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?d2c4f11d-20bb-0f6c-354a-1cb2a1ede9d9>