虚机配置USB CDROM设备热迁移crash 问题现象 定位过程 堆栈分析 日志分析 打开trace 异常日志 上下文分析 正常日志 异常堆栈 修复方案 结论 基础原理
问题现象
dogfood环境一台虚机热迁移概率性触发HA重建,重建直接原因是热迁移目的端虚机qemu进程crash。目的端查看crash生成的coredump堆栈如下:
Core was generated by `/usr/libexec/qemu-kvm -name guest=e055063b-c5ec-4e0f-aca0-bc7e857a3522,debug-th'.
Program terminated with signal SIGSEGV, Segmentation fault.
#0 __memmove_sse2_unaligned_erms () at ../sysdeps/x86_64/multiarch/memmove-vec-unaligned-erms.S:312
312 movq -8(%rsi,%rdx), %rcx
[Current thread is 1 (Thread 0x7f3d52d16f00 (LWP 311125))]
(gdb) bt
#0 __memmove_sse2_unaligned_erms () at ../sysdeps/x86_64/multiarch/memmove-vec-unaligned-erms.S:312
#1 0x0000560fdea556ae in memcpy (__len=8, __src=<optimized out>, __dest=<optimized out>) at /usr/include/bits/string_fortified.h:34
#2 iov_from_buf_full (iov=<optimized out>, iov_cnt=<optimized out>, offset=<optimized out>, buf=0x0, bytes=bytes@entry=8) at util/iov.c:33
#3 0x0000560fde8f42d9 in iov_from_buf (bytes=8, buf=<optimized out>, offset=<optimized out>, iov_cnt=<optimized out>, iov=<optimized out>) at /usr/src/debug/qemu-kvm-ev-2.12.0-44.1.oe1.1.smartx.140.x86_64/include/qemu/iov.h:49
#4 usb_packet_copy (p=p@entry=0x560fe1577dc0, ptr=<optimized out>, bytes=bytes@entry=8) at hw/usb/core.c:603
#5 0x0000560fde9066fd in usb_msd_copy_data (s=0x560fe2741000, p=0x560fe1577dc0) at hw/usb/dev-storage.c:230
#6 0x0000560fde906d16 in usb_msd_handle_data (dev=0x560fe2741000, p=0x560fe1577dc0) at hw/usb/dev-storage.c:535
#7 0x0000560fde8f47cc in usb_handle_packet (dev=0x560fe2741000, p=p@entry=0x560fe1577dc0) at hw/usb/core.c:424
#8 0x0000560fde8f9ed0 in uhci_handle_td (s=s@entry=0x560fe2826000, q=0x560fe2e02880, q@entry=0x0, qh_addr=qh_addr@entry=869127938, td=td@entry=0x7fff40e82470, td_addr=1920348032, int_mask=int_mask@entry=0x7fff40e82464) at hw/usb/hcd-uhci.c:896
#9 0x0000560fde8fa429 in uhci_process_frame (s=s@entry=0x560fe2826000) at hw/usb/hcd-uhci.c:1072
#10 0x0000560fde8fa7dd in uhci_frame_timer (opaque=0x560fe2826000) at hw/usb/hcd-uhci.c:1171
#11 0x0000560fdea4dc3c in timerlist_run_timers (timer_list=0x560fe15ffb20) at util/qemu-timer.c:536
#12 0x0000560fdea4de87 in qemu_clock_run_timers (type=QEMU_CLOCK_VIRTUAL) at util/qemu-timer.c:547
#13 qemu_clock_run_all_timers () at util/qemu-timer.c:674
#14 0x0000560fdea4e361 in main_loop_wait (nonblocking=<optimized out>) at util/main-loop.c:503
#15 0x0000560fde6f0ffa in main_loop () at vl.c:2059
虚机配置有usb总线的cdrom设备,xml信息如下:
<disk type='file' device='cdrom'><driver name='qemu' type='raw'/><source file='/usr/share/smartx/images/vmtools/30cc344e-2b2e-4896-8cc8-4e7435919655'/><backingStore/><target dev='sda' bus='usb'/><readonly/><alias name='usb-disk0'/><address type='usb' bus='0' port='2'/></disk>
<controller type='usb' index='0' model='piix3-uhci'><alias name='usb'/><address type='pci' domain='0x0000' bus='0x00' slot='0x01' function='0x2'/></controller>
热迁移目的端虚机qemu进程crash时间点日志如下:
2024-03-11 10:47:25.482+0000: starting up libvirt version: 6.2.0
......
-drive file=/usr/share/images/vmtools/30cc344e-2b2e-4896-8cc8-4e7435919655,format=raw,if=none,id=drive-usb-disk0,media=cdrom,readonly=on
-device usb-storage,bus=usb.0,port=2,drive=drive-usb-disk0,id=usb-disk0,bootindex=999,removable=off
......
2024-03-11 10:47:25.482+0000: Domain id=181 is tainted: custom-argv
2024-03-11T10:47:25.631064Z qemu-kvm: -chardev pty,id=charserial0: char device redirected to /dev/pts/59 (label charserial0)
virtio-net-pci.rom size=262144 initialize as resizeable
2024-03-11 10:47:53.911+0000: shutting down, reason=crashed
配置usb-cdrom设备的虚机热迁移,会概率性触发目的端虚机qemu进程crash,其它虚机反复热迁移不会出现。结合crash堆栈和虚机配置,初步猜测crash是由于热迁移对usb-cdrom设备的处理不当造成。 Libvirt/QEMU版本信息:
$ virsh version
Compiled against library: libvirt 6.2.0
Using library: libvirt 6.2.0
Using API: QEMU 6.2.0
Running hypervisor: QEMU 2.12.0
定位过程
堆栈分析
Core was generated by `/usr/libexec/qemu-kvm -name guest=e055063b-c5ec-4e0f-aca0-bc7e857a3522,debug-th'.
Program terminated with signal SIGSEGV, Segmentation fault.
#0 __memmove_sse2_unaligned_erms () at ../sysdeps/x86_64/multiarch/memmove-vec-unaligned-erms.S:312
312 movq -8(%rsi,%rdx), %rcx
[Current thread is 1 (Thread 0x7f3d52d16f00 (LWP 311125))]
(gdb) bt
#0 __memmove_sse2_unaligned_erms () at ../sysdeps/x86_64/multiarch/memmove-vec-unaligned-erms.S:312
#1 0x0000560fdea556ae in memcpy (__len=8, __src=<optimized out>, __dest=<optimized out>) at /usr/include/bits/string_fortified.h:34
#2 iov_from_buf_full (iov=<optimized out>, iov_cnt=<optimized out>, offset=<optimized out>, buf=0x0, bytes=bytes@entry=8) at util/iov.c:33
#3 0x0000560fde8f42d9 in iov_from_buf (bytes=8, buf=<optimized out>, offset=<optimized out>, iov_cnt=<optimized out>, iov=<optimized out>) at /usr/src/debug/qemu-kvm-ev-2.12.0-44.1.oe1.1.smartx.140.x86_64/include/qemu/iov.h:49
#4 usb_packet_copy (p=p@entry=0x560fe1577dc0, ptr=<optimized out>, bytes=bytes@entry=8) at hw/usb/core.c:603
#5 0x0000560fde9066fd in usb_msd_copy_data (s=0x560fe2741000, p=0x560fe1577dc0) at hw/usb/dev-storage.c:230
#6 0x0000560fde906d16 in usb_msd_handle_data (dev=0x560fe2741000, p=0x560fe1577dc0) at hw/usb/dev-storage.c:535
#7 0x0000560fde8f47cc in usb_handle_packet (dev=0x560fe2741000, p=p@entry=0x560fe1577dc0) at hw/usb/core.c:424
#8 0x0000560fde8f9ed0 in uhci_handle_td (s=s@entry=0x560fe2826000, q=0x560fe2e02880, q@entry=0x0, qh_addr=qh_addr@entry=869127938, td=td@entry=0x7fff40e82470, td_addr=1920348032, int_mask=int_mask@entry=0x7fff40e82464) at hw/usb/hcd-uhci.c:896
#9 0x0000560fde8fa429 in uhci_process_frame (s=s@entry=0x560fe2826000) at hw/usb/hcd-uhci.c:1072
#10 0x0000560fde8fa7dd in uhci_frame_timer (opaque=0x560fe2826000) at hw/usb/hcd-uhci.c:1171
#11 0x0000560fdea4dc3c in timerlist_run_timers (timer_list=0x560fe15ffb20) at util/qemu-timer.c:536
#12 0x0000560fdea4de87 in qemu_clock_run_timers (type=QEMU_CLOCK_VIRTUAL) at util/qemu-timer.c:547
#13 qemu_clock_run_all_timers () at util/qemu-timer.c:674
#14 0x0000560fdea4e361 in main_loop_wait (nonblocking=<optimized out>) at util/main-loop.c:503
#15 0x0000560fde6f0ffa in main_loop () at vl.c:2059
#16 main (argc=<optimized out>, argv=<optimized out>, envp=<optimized out>) at vl.c:4822
(gdb) frame 2 // memcpy函数执行内存拷贝,引发段错误
#2 iov_from_buf_full (iov=<optimized out>, iov_cnt=<optimized out>, offset=<optimized out>, buf=0x0, bytes=bytes@entry=8) at util/iov.c:33
33 memcpy(iov[i].iov_base + offset, buf + done, len);
(gdb) list
28 size_t done;
29 unsigned int i;
30 for (i = 0, done = 0; (offset || done < bytes) && i < iov_cnt; i++) {
31 if (offset < iov[i].iov_len) {
32 size_t len = MIN(iov[i].iov_len - offset, bytes - done);
33 memcpy(iov[i].iov_base + offset, buf + done, len);
34 done += len;
35 offset = 0;
36 } else {
37 offset -= iov[i].iov_len;
(gdb) p buf // 内存拷贝的源端指针buf为NULL,空指针引用引起的段错误
$1 = (const void *) 0x0
(gdb) p bytes
$2 = 8
(gdb) frame 5
#5 0x0000560fde9066fd in usb_msd_copy_data (s=0x560fe2741000, p=0x560fe1577dc0) at hw/usb/dev-storage.c:230
230 usb_packet_copy(p, scsi_req_get_buf(s->req) + s->scsi_off, len);
(gdb) list
225 {
226 uint32_t len;
227 len = p->iov.size - p->actual_length;
228 if (len > s->scsi_len)
229 len = s->scsi_len;
230 usb_packet_copy(p, scsi_req_get_buf(s->req) + s->scsi_off, len);
231 s->scsi_len -= len;
232 s->scsi_off += len;
233 if (len > s->data_len) {
234 len = s->data_len;
(gdb) p *s->req
$3 = {bus = 0x560fe27426d8, dev = 0x560fe2110280, ops = 0x560fdef91060 <scsi_disk_emulate_reqops>, refcount = 2, tag = 46120, lun = 0, status = 4294967295, hba_private = 0x0, resid = 8, cmd = {buf = "J\001\000\000\020\000\000\000\b\000\000\000\000\000\000", len = 10,xfer = 8, lba = 4096, mode = SCSI_XFER_FROM_DEV}, cancel_notifiers = {notifiers = {lh_first = 0x0}},sense = "\301\377\377\377\301\377\377\377\301\377\377\377\301\377\377\377\301\377\377\377\301\377\377\377\301\377\377\377\301\377\377\377\301\377\377\377\301\377\377\377\301\377\377\377\301\377\377\377\301\377\377\377\301\377\377\377\301\377\377\377\301\377\377\377\301\377\377\377\301\377\377\377\301\377\377\377\301\377\377\377\301\377\377\377\301\377\377\377\301\377\377\377\301\377\377\377\301\377\377\377\301\377\377\377\301\377\377\377\301\377\377\377\301\377\377\377\301\377\377\377\301\377\377\377\301\377\377\377\301\377\377\377\301\377\377\377\301\377\377\377\301\377\377\377\301\377\377\377\301\377\377\377\301\377\377\377\301\377\377\377\301\377\377\377\301\377\377\377\301\377\377\377\301\377\377\377\301\377\377\377\301\377\377\377\301\377\377\377\301\377\377\377\301\377\377\377\301\377\377\377"..., sense_len = 0, enqueued = true, io_canceled = false, retry = false, dma_started = false, aiocb = 0x0, sg = 0x0, next = {tqe_next = 0x0, tqe_prev = 0x560fe2110450}}
(gdb) p ((SCSIDiskReq *)s->req)->iov // scsi request数据结构中,关联的内存指针为空
$4 = {iov_base = 0x0, iov_len = 0}
根据上述堆栈分析,引发QEMU进程crash的原因是段错误:usb_packet_copy
在拷贝数据时将scsi request中iov内存指针作为源数据,该指针为空导致处于调用链最底层的memcpy
函数在拷贝内存时触发段错误。除此以外,没有其他有用的线索。
日志分析
打开trace
基于crash产生规律,ubuntu虚机挂载usb-cdrom后反复热迁移过程中容易复现此问题,Libvirt虚机XML增加如下命令行,使能trace
<qemu:commandline><qemu:arg value='-trace'/><qemu:arg value='events=/home/work/events'/>
</qemu:commandline>
设置usb和scsi_req相关的trace点如下:
$ cat /home/work/events
usb_*
scsi_req_*
异常日志
之后尝试反复热迁移虚拟机,复现成功,源端UHCI控制器在热迁移前处理的最后一帧数据,其日志如下:
324808@1711972823.521945:usb_uhci_frame_start nr 319 // 时间帧索引:319
324808@1711972823.521978:usb_uhci_qh_load qh 0x35cb5400 // 处理frame list上的qh
324808@1711972823.521989:usb_uhci_qh_load qh 0x35cb5480 // 处理frame list上的qh
324808@1711972823.521997:usb_uhci_td_load qh 0x35cb5480, td 0x35cbe000, ctrl 0x0, token 0xffe07f69 // 处理frame list上的td
324808@1711972823.522010:usb_uhci_td_nextqh qh 0x35cb5480, td 0x35cbe000 // 处理frame list上的下一个qh
324808@1711972823.522022:usb_uhci_qh_load qh 0x35cb5680 // 处理qh
324808@1711972823.522030:usb_uhci_td_load qh 0x35cb5680, td 0x75ac5180, ctrl 0x19800000, token 0x3c903e1 // 处理td
324808@1711972823.522045:usb_uhci_packet_add token 0x103e1, td 0x75ac5180 // 数据方向为 device->memory,预先为数据分配内存
324808@1711972823.522056:usb_packet_state_change bus 0, port 2, ep 2, packet 0x559f9ba14b00, state undef -> setup
/* 执行CBW描述的命令,从设备读取数据到host */
324808@1711972823.522079:usb_msd_cmd_submit lun 0, tag 0x472, flags 0x00000080, len 10, data-len 8
324808@1711972823.522107:scsi_req_parsed target 0 lun 0 tag 1138 command 74 dir 1 length 8 // usb命令转化为scsi命令
324808@1711972823.522124:scsi_req_parsed_lba target 0 lun 0 tag 1138 command 74 lba 4096
324808@1711972823.522139:scsi_req_alloc target 0 lun 0 tag 1138 // 创建scsi request
324808@1711972823.522169:scsi_req_continue target 0 lun 0 tag 1138
324808@1711972823.522181:scsi_req_data target 0 lun 0 tag 1138 len 8 // scsi request请求从device读取8字节数据
324808@1711972823.522194:usb_packet_state_change bus 0, port 2, ep 2, packet 0x559f9ba14b00, state setup -> complete
324808@1711972823.522209:usb_uhci_packet_complete_success token 0x103e1, td 0x75ac5180
324808@1711972823.522219:usb_uhci_packet_del token 0x103e1, td 0x75ac5180
324808@1711972823.522232:usb_uhci_td_complete qh 0x35cb5680, td 0x75ac5180
2024-04-01 12:00:22.142+0000: starting up libvirt version: 6.2.0
...
3286206@1711972823.951646:usb_uhci_frame_start nr 320 // 时间帧索引:320
3286206@1711972823.951663:usb_uhci_qh_load qh 0x35cb5100 // 处理frame list上的qh
3286206@1711972823.951671:usb_uhci_qh_load qh 0x35cb5480 // 处理frame list上的qh
3286206@1711972823.951680:usb_uhci_td_load qh 0x35cb5480, td 0x35cbe000, ctrl 0x1000000, token 0xffe07f69 // 处理frame list上的td
3286206@1711972823.951693:usb_uhci_td_nextqh qh 0x35cb5480, td 0x35cbe000
3286206@1711972823.951702:usb_uhci_qh_load qh 0x35cb5700
3286206@1711972823.951709:usb_uhci_td_load qh 0x35cb5700, td 0x75ac5240, ctrl 0x39800000, token 0xe08369
3286206@1711972823.951727:usb_uhci_queue_add token 0x8369
3286206@1711972823.951735:usb_uhci_packet_add token 0x8369, td 0x75ac5240
3286206@1711972823.951746:usb_packet_state_change bus 0, port 2, ep 1, packet 0x56066b2fb5a0, state undef -> setup
3286206@1711972823.951766:usb_msd_data_in 8/8 (scsi 8) // 从usb-cdrom设备读取数据
2024-04-01 12:00:24.665+0000: shutting down, reason=crashed // 触发crash
上下文分析
Specification
USB CDROM设备,即基于USB协议的CDROM,该设备被划入USB大容量存储设备,其数据作为USB协议的payload被传输,传输的实现遵循USB大容量存储Bulk-Only传输规范。 Bulk-Only传输规范定义了传输数据的种类、流程以及具体格式,支持四种类型的数据,分别是:
Command - 命令数据,命令数据传输通过Command Block Wrapper(CBW)描述 Data-In - 读入数据,从USB设备读入数据到host Data-Out - 写出数据,host向USB设备写入数据 Status - 命令状态数据,命令状态数据传输通过Command Status Wrapper(CSW)描述
enum USBMSDMode {USB_MSDM_CBW, /* Command Block. */USB_MSDM_DATAOUT, /* Transfer data to device. */USB_MSDM_DATAIN, /* Transfer data from device. */USB_MSDM_CSW /* Command Status. */
};
CBW
CBW是命令描述块,作为一个31字节的数据包在USB协议层从host侧被传输的USB设备侧,USB解析CBW并执行其描述的命令,CBW命令格式如下: QEMU定义如下:
struct usb_msd_cbw {uint32_t sig; // 标识一个CSW包,0x43425355uint32_t tag; // 用于跟踪device执行的命令,device一旦完成该命令,将CBW中的tag字段填入CSW返回uint32_t data_len; // CBW描述的是数据传输时,该字段记录要传输的数据长度uint8_t flags; // 标记数据传输方向,0表示从host到device,1表示device到hostuint8_t lun; // 当USB设备支持多个LUN时,该字段指明命令在哪个LUN执行uint8_t cmd_len; // 设备执行的命令长度uint8_t cmd[16]; // 设备执行的命令
};
CSW
CSW是命令状态描述块,作为一个13字节的短数据包在USB协议层从device侧被传输的host设备侧,当设备完成CBW描述的命令后,将描述命令执行结果的所有信息封装到CSW中,返回给host,一个CSW对应一个CBW,其具体格式如下: QEMU定义如下:
struct QEMU_PACKED usb_msd_csw {uint32_t sig; // 标记一个CSW包,0x53425355huint32_t tag; // CBW中的tag,USB设备执行完一条CBW描述的命令之后,将其tag取出,封装成CSW返回给host,表示命令执行完成uint32_t residue; // 当设备执行数据读写时,如果实际长度不及CBW期望长度,该字段记录读写剩余长度(即CBW.data_len - 实际长度)uint8_t status; // 描述命令执行状态,0表示执行成功,1表示失败
};
命令执行
QEMU设计了usb-storage-dev
和usb-storage
两个设备类型用于实现USB大容量存储设备的模拟,其中usb-storage-dev是usb-storage的父类,它实现了USB大容量存储Bulk-Only传输规范,usb-storage继承了该规范,实现了USB CDROM的模拟,下面分析QEMU中如何实现上述传输规范。 USB CDROM设备对CBW和CSW包的处理,都在usb_msd_handle_data
函数中实现:
usb_msd_handle_data/* pid是从USB包元数据信息中提取的包方向 */switch (p->pid) {/* 对于host到device方向的包,只能是CBW或者写数据包(DATAOUT) */case USB_TOKEN_OUT:switch (s->mode) {case USB_MSDM_CBW:case USB_MSDM_DATAOUT:default:goto fail;}break;/* 对于device到host方向的包,可能是CSW或者读数据包或者伪写数据包 */case USB_TOKEN_IN:switch (s->mode) {case USB_MSDM_DATAOUT:case USB_MSDM_CSW:case USB_MSDM_DATAIN:default:goto fail;}break;
发送读命令
假设现在CBW中包含一条读命令,分析usb_msd_handle_data
中处理USB_MSDM_CBW包的逻辑:
switch (s->mode) {case USB_MSDM_CBW:if (p->iov.size != 31) { /* 不满足协议规定的31字节长度 */error_report("usb-msd: Bad CBW size");goto fail;}/* 从指针p关联的iov中取出USB package,将其赋值给cbw* 这里可以看出,Bulk-Only协议层的包作为USB协议的payload被传输 */usb_packet_copy(p, &cbw, 31); /* 验证签名是否为协议规定的ID */if (le32_to_cpu(cbw.sig) != 0x43425355) {error_report("usb-msd: Bad signature %08x",le32_to_cpu(cbw.sig));goto fail;}/* 根据cbw中的lun,查找scsi总线下对应的scsi设备* 这里可以看出,QEMU在模拟USB大容量存储时,虽然按照Bulk-Only协议实现了包的传输* 但在设备具体执行CBW时,却没有按照每个具体存储设备的硬件行为来模拟,而是用scsi设备来代替了后端实现 */scsi_dev = scsi_device_find(&s->bus, 0, 0, cbw.lun);if (scsi_dev == NULL) {error_report("usb-msd: Bad LUN %d", cbw.lun);goto fail;}/* 获取CBW描述的命令的tag */tag = le32_to_cpu(cbw.tag);/* 获取CBW中数据传输长度字段 */s->data_len = le32_to_cpu(cbw.data_len);/* 如果数据传输长度为0,表明设备执行的命令不是数据读写 */if (s->data_len == 0) {/* 没有数据传输,下一次在Bulk-Only协议层传输的包就是CSW */s->mode = USB_MSDM_CSW;} else if (cbw.flags & 0x80) {/* 如果有数据长度,且flags的为0x80,根据规范为数据读入命令 */s->mode = USB_MSDM_DATAIN;} else {/* 如果有数据长度,且flags的0x00,根据规范为数据写出命令 */s->mode = USB_MSDM_DATAOUT;}trace_usb_msd_cmd_submit(cbw.lun, tag, cbw.flags,cbw.cmd_len, s->data_len);assert(le32_to_cpu(s->csw.residue) == 0);s->scsi_len = 0;/* 将针对一个USB大容量存储设备的CBW命令,转换为一个针对scsi设备的scsi request,封装scsi request */s->req = scsi_req_new(scsi_dev, tag, cbw.lun, cbw.cmd, cbw.cmd_len, NULL);if (s->commandlog) {scsi_req_print(s->req);}/* 向scsi设备提交request, request中包含了期望scsi设备执行的scsi 命令* 这里可以看出,QEMU使用scsi设备代替了USB大容量存储设备的后端* 两种设备在命令执行的行为上类似,发往USB设备期望其执行的命令被转化为发往scsi设备的命令 * QEMU对scsi设备的模拟,其核心内容是将scsi命令分类,每一类命令对应实现操作函数* 对于非读写scsi命令,QEMU实现了scsi_disk_emulate_reqops处理这类命令* 对于读写scsi命令,QEMU实现了scsi_disk_dma_reqops处理 */len = scsi_req_enqueue(s->req);if (len) {/* 函数返回设备期望读写的数据长度,非0表示scsi设备命令执行完成后需要读写数据 * 该函数执行完成代表整个CBW被USB CDROM设备执行完成,而执行的结果会根据CBW命令的不同存放到不同数据结构中* 对于非读写scsi命令,设备执行命令后返回的数据会被放在scsi_req_get_buf(req)返回的缓存区 */scsi_req_continue(s->req);}break;
host(这里是指从Guest OS系统角度出发看到大host)与USB CDROM设备之间的数据包传输,可以分为三个步骤,第一个步骤是UHCI从frame list中读取TD,根据TD的描述解析数据方向,发起USB数据包传输;第二个步骤是在host与USB CDROM之间传输数据包,USB CDROM根据Bulk-Only协议规范解析该数据包,做对应的读写处理;第三个步骤是设备执行数据读写操作。目前,为保证行文连贯,我们仅分析了第二步骤,第一步和第三步在后续章节补充。 总结,CBW描述读命令被USB CDROM执行完成后:
MSDState对象中的mode被设置为数据读(USB_MSDM_DATAIN),标记设备处于读模式,下一次USB协议层有读请求(USB_TOKEN_IN)时会根据mode的值做对应处理 SCSI设备在代替USB CDROM设备执行完读命令后,将读命令的返回数据放到了scsi_req_get_buf(req)指向的缓存区,下一次USB协议层发起读请求(USB_TOKEN_IN)时,USB CDROM的处理逻辑是找到该缓存区,取出数据返回
读取数据
分析usb_msd_handle_data
中处理数据读的逻辑:
case USB_MSDM_DATAIN:trace_usb_msd_data_in(p->iov.size, s->data_len, s->scsi_len);/* s指针指向一个MSDState对象,如果scsi_len字段不为0,表示CBW命令执行后有数据返回 */if (s->scsi_len) {/* s中包含的scsi request完成后将返回的数据,p指向usb协议层的数据包* 将s中存放的CBW执行结果拷贝到p中 */usb_msd_copy_data(s, p);}/* 如果实际读取的数据不及CBW中期望的数据长度,保持读模式USB_MSDM_DATAIN不变,否则更新为USB_MSDM_CSW模式 */if (le32_to_cpu(s->csw.residue)) {len = p->iov.size - p->actual_length;if (len) {usb_packet_skip(p, len);if (len > s->data_len) {len = s->data_len;}s->data_len -= len;if (s->data_len == 0) {s->mode = USB_MSDM_CSW;}}}if (p->actual_length < p->iov.size && s->mode == USB_MSDM_DATAIN) {trace_usb_msd_packet_async();s->packet = p;p->status = USB_RET_ASYNC;}break;
下图可以描述USB CDROM设备处理一条读命令的完整流程:
设备读取USB协议层传输的数据,根据Bulk_Only协议解析其格式,得到CBW 设备提取CBW信息,执行对应的读写命令,或者其它操作 设备执行CBW描述的命令后,封装CSW包,将其作为USB的payload,返回给host
正常日志
开启trace,通过日志继续理解一条读命令的流程:
324808@1711972820.919236:usb_uhci_frame_start nr 293 // UHCI处理索引为293的时间帧
324808@1711972820.919262:usb_uhci_qh_load qh 0x35cb5400 // 根据UHCI规范加载QH
324808@1711972820.919271:usb_uhci_qh_load qh 0x35cb5480
// 根据UHCI规范加载TD
324808@1711972820.919277:usb_uhci_td_load qh 0x35cb5480, td 0x35cbe000, ctrl 0x0, token 0xffe07f69
324808@1711972820.919287:usb_uhci_td_nextqh qh 0x35cb5480, td 0x35cbe000 // 根据UHCI规范加载下一个QH
324808@1711972820.919295:usb_uhci_qh_load qh 0x35cb5680 // 根据UHCI规范加载QH
// 根据UHCI规范加载TD
324808@1711972820.919303:usb_uhci_td_load qh 0x35cb5680, td 0x75ac5240, ctrl 0x19800000, token 0x3c103e
// 准备传输USB packet,首先为packet分配内存空间
324808@1711972820.919317:usb_uhci_packet_add token 0x103e1, td 0x75ac5240
// 初始化USB packet其它信息,将TD描述的数据传输信息存放到package中,将packet状态从undef设置为setup,
// 之后为packet准备数据,如果是发往device的packet,需要先从host内存中读取数据填入packet,反之则不需要
// 对于读命令,它是一个封装为CBW的,发往device的packet,因此需要从host内存中将具体的读命令填入CBW
// bus: 0 表示usb设备位于总线0
// port: 2 表示usb设备端口号为2
// ep: 2 一个usb设备可以拥有多个endpoint,每个ep可以独立传输数据,对于USB CDROM
// Bulk-Only规范规定至少需要实现2个ep,一个是Bulk-In ep,一个是Bulk-Out ep,Bulk-Out ep号为2
// 如果用 一个三元组(bus, port, ep)表示USB packet的目标地址,则USB packet发送的目的地是(0,2,2)
324808@1711972820.919325:usb_packet_state_change bus 0, port 2, ep 2, packet 0x559f9b6a1b00, state undef -> setup
// 将CBW中的读命令提交给USB设备,tag 0x471跟踪一个CBW命令的执行情况
324808@1711972820.919344:usb_msd_cmd_submit lun 0, tag 0x471, flags 0x00000080, len 10, data-len 8
// SB设备将该命令转化为scsi request,tag 1137跟踪一个scsi request的执行情况
324808@1711972820.919358:scsi_req_parsed target 0 lun 0 tag 1137 command 74 dir 1 length 8
324808@1711972820.919370:scsi_req_parsed_lba target 0 lun 0 tag 1137 command 74 lba 4096
324808@1711972820.919384:scsi_req_alloc target 0 lun 0 tag 1137
324808@1711972820.919399:scsi_req_continue target 0 lun 0 tag 1137
// scsi设备执行scsi request携带的读命令,读命令读取8字节数据
324808@1711972820.919408:scsi_req_data target 0 lun 0 tag 1137 len 8
// scsi设备读取的8字节数据放在了scsi_req_get_buf(req)返回指针指向的内存中
324808@1711972820.919418:usb_packet_state_change bus 0, port 2, ep 2, packet 0x559f9b6a1b00, state setup -> complete
324808@1711972820.919431:usb_uhci_packet_complete_success token 0x103e1, td 0x75ac5240
324808@1711972820.919439:usb_uhci_packet_del token 0x103e1, td 0x75ac5240
324808@1711972820.919449:usb_uhci_td_complete qh 0x35cb5680, td 0x75ac5240
......
// host向device发送的读命令作为USB协议的payload,在一个时间帧内被UHCI发送到device,并执行完成。
// 下一个时间帧中UHCI处理的TD,描述的是device向host传输的数据(从device读取数据),数据就是上一帧读到的8字节数据
324808@1711972821.019279:usb_uhci_frame_start nr 294
324808@1711972821.019309:usb_uhci_qh_load qh 0x35cb5380
324808@1711972821.019317:usb_uhci_qh_load qh 0x35cb5480
324808@1711972821.019326:usb_uhci_td_load qh 0x35cb5480, td 0x35cbe000, ctrl 0x1000000, token 0xffe07f69
324808@1711972821.019338:usb_uhci_td_nextqh qh 0x35cb5480, td 0x35cbe000
324808@1711972821.019346:usb_uhci_qh_load qh 0x35cb5700
// UHCI加载TD
324808@1711972821.019357:usb_uhci_td_load qh 0x35cb5700, td 0x75ac5200, ctrl 0x39800000, token 0xe08369
// 准备传输USB packet,首先为packet分配内存空间
324808@1711972821.019372:usb_uhci_packet_add token 0x8369, td 0x75ac5200
// USB packet从(0,2,1)的目标地址读出,返回给host
324808@1711972821.019380:usb_packet_state_change bus 0, port 2, ep 1, packet 0x559f9cd59780, state undef -> setup
// CBW执行完成后读到的数据被放在scsi_req_get_buf(req)指向的缓存,将其读出,填入到USB packet中
324808@1711972821.019397:usb_msd_data_in 8/8 (scsi 8)
// 成功读取到scsi request返回的数据后,告诉scsi device继续执行请求,如果仍然有数据,继续读取
324808@1711972821.019406:scsi_req_continue target 0 lun 0 tag 1137
// scsi request执行完成,没有别的数据读写后,将scsi request从请求队列中摘出,scsi request完成
324808@1711972821.019416:scsi_req_dequeue target 0 lun 0 tag 1137
// CBW命令完成
324808@1711972821.019425:usb_msd_cmd_complete status 0, tag 0x471
324808@1711972821.019435:usb_packet_state_change bus 0, port 2, ep 1, packet 0x559f9cd59780, state setup -> complete
324808@1711972821.019451:usb_uhci_packet_complete_success token 0x8369, td 0x75ac5200
324808@1711972821.019460:usb_uhci_packet_del token 0x8369, td 0x75ac5200
分析正常的日志,对于一个真实的物理USB设备,HOST从USB设备读取数据的大致逻辑为: 当HOST(这里理解为Guest OS)向USB设备发起读请求时,请求首先由Guest OS的UHCI驱动转化为TD放入Frame List中,UHCI硬件负责同USB设备的数据传输,而TD描述了UHCI驱动期望UHCI硬件从USB侧读取或者写入的数据。UHCI驱动把读请求组织成至少两个TD,分别为发送数据到USB设备的描述符(TD)和从USB设备读取数据的描述符(TD),发送到USB设备的数据为Bulk-Only协议定义的CBW,它发往USB设备的Bulk-Out端点(endpoint);从USB设备读取的数据为Bulk-Only协议定义的Bulk-In,它从USB设备的Bulk-In端点(endpoint)读取数据。两个TD分别在Frame List的两个帧中被处理。 QEMU在模拟USB CDROM设备时,遵循了上述逻辑,同时模拟了UHCI,按照Bulk-Only规范实现了UHCI与USB CDROM之间的数据传输,唯一不同的地方在于QEMU在模拟CDROM时后端使用了SCSI设备来代替: QEMU模拟的USB CDROM在遵循Bulk-Only规范处理CBW时,对于数据读取,QEMU将其转化SCSI请求提交到SCSI设备上,将执行过程中读到的数据放到一个临时缓存中,即上文描述的scsi_req_get_buf(req)返回值指向的内存区域。当UHCI处理Frame List下一帧时,TD描述的是从Bulk-In端点读数据,因此USB CDROM直接将 scsi_req_get_buf(req)指向的数据返回给UHCI,完成TD描述的数据传输。 真实的USB设备中,CBW执行后的结果存放到了USB设备中,等待UHCI处理下一个TD时读取;虚拟化环境下,CBW执行后的结果存放到了内存中,等待UHCI处理下一个TD时读取。而后者由软件实现,因此可能出现Bug,本文中描述的问题正是由此引发: 当Guest OS读取USB设备时,在UHCI处理两个TD之间的时间窗口,发生了热迁移,即第一个TD在源端被UHCI处理,第二个TD在目标端被UHCI处理,则热迁移需要保证第一个TD产生的数据被迁移,否则第二个TD在目标端被处理时没有数据可读,会引发UHCI工作异常,继而触发crash。
异常堆栈
本文描述的问题正是热迁移过程中没有迁移TD处理产生的数据导致,即没有迁移scsi request请求产生的数据。我们再次分析问题堆栈可以印证:
(gdb) bt
#0 0x00007f0a90e0b15e in ?? () from /lib64/libc.so.6
#1 0x000056066a38662f in memcpy (__len=8, __src=<optimized out>, __dest=<optimized out>) at /usr/include/bits/string_fortified.h:34
#2 iov_from_buf_full (iov=<optimized out>, iov_cnt=<optimized out>, offset=<optimized out>, buf=0x0, bytes=bytes@entry=8) at ../util/iov.c:33
#3 0x000056066a07b4d9 in iov_from_buf (bytes=8, buf=<optimized out>, offset=<optimized out>, iov_cnt=<optimized out>, iov=<optimized out>)at /usr/src/debug/qemu-6-6.2.0-75.7.oe1.smartx.git.40.x86_64/include/qemu/iov.h:49
#4 usb_packet_copy (p=p@entry=0x56066b2fb5a0, ptr=<optimized out>, bytes=bytes@entry=8) at ../hw/usb/core.c:636
#5 0x000056066a09acfd in usb_msd_copy_data (s=s@entry=0x56066c62c770, p=p@entry=0x56066b2fb5a0) at ../hw/usb/dev-storage.c:186
#6 0x000056066a09b59f in usb_msd_handle_data (dev=0x56066c62c770, p=0x56066b2fb5a0) at ../hw/usb/dev-storage.c:496
#7 0x000056066a07ba8c in usb_handle_packet (dev=0x56066c62c770, p=p@entry=0x56066b2fb5a0) at ../hw/usb/core.c:455
#8 0x000056066a0809b8 in uhci_handle_td (s=s@entry=0x56066bd5f210, q=0x56066bb7fbd0, q@entry=0x0, qh_addr=qh_addr@entry=902518530, td=td@entry=0x7fffe6e788f0, td_addr=<optimized out>,int_mask=int_mask@entry=0x7fffe6e788e4) at ../hw/usb/hcd-uhci.c:885
#9 0x000056066a081259 in uhci_process_frame (s=s@entry=0x56066bd5f210) at ../hw/usb/hcd-uhci.c:1061
#10 0x000056066a081b35 in uhci_frame_timer (opaque=opaque@entry=0x56066bd5f210) at ../hw/usb/hcd-uhci.c:1159
#11 0x000056066a391120 in timerlist_run_timers (timer_list=0x56066af26bd0) at ../util/qemu-timer.c:642
#12 0x000056066a391317 in qemu_clock_run_timers (type=QEMU_CLOCK_VIRTUAL) at ../util/qemu-timer.c:656
#13 qemu_clock_run_all_timers () at ../util/qemu-timer.c:738
#14 0x000056066a38dd93 in main_loop_wait (nonblocking=nonblocking@entry=0) at ../util/main-loop.c:542
#15 0x000056066a1620ac in qemu_main_loop () at ../softmmu/runstate.c:739
#16 0x0000560669ec0e2c in main (argc=<optimized out>, argv=<optimized out>, envp=<optimized out>) at ../softmmu/main.c:52
(gdb) frame 5
#5 0x000056066a09acfd in usb_msd_copy_data (s=s@entry=0x56066c62c770, p=p@entry=0x56066b2fb5a0) at ../hw/usb/dev-storage.c:186
186 usb_packet_copy(p, scsi_req_get_buf(s->req) + s->scsi_off, len);
// 目标端UHCI处理TD,该TD期望UHCI从USB设备的Bulk-In端点读取读取8字节数据
// 这里USB CDROM假定了UHCI处理上一个TD,执行CBW的结果放在了scsi_req_get_buf(s->req)
// 因此直接拷贝该指针指向的内存,而热迁移并没有将这段内存一并迁移,导致进程crash
// 这里我们打印出scsi request中存放的CBW的tag,这个tag正好和源端UHCI在上一个时间帧处理的CBW tag相同
(gdb) p/x s->req->tag
$1 = 0x472
修复方案
从上述分析来看,热迁移过程中如果有正在处理的scsi request时,需要保证迁移前后数据视图一致,这里有两种解决方案:
如果scsi request支持重试,热迁移过程中可以取消正在被处理的scsi request,让其在迁移目标端被 重试 如果scsi request不支持重试,可以直接将scsi request产生的数据一并迁移,保证两端数据视图一致
结论
基础原理
设备模型
USB CDROM设备命令行参数举例如下,device选项driver参数为usb-storage,因此Guest OS看到的是一个USB设备,它的drive指向一个以本地文件为存储介质的CDROM,用QEMU的术语来说,即一个IO protocol为file的drive。
-drive file=/usr/share/images/vmtools/30cc344e-2b2e-4896-8cc8-4e7435919655,format=raw,if=none,id=drive-usb-disk0,media=cdrom,readonly=on
-device usb-storage,bus=usb.0,port=2,drive=drive-usb-disk0,id=usb-disk0,bootindex=999,removable=off
SCSI命令可以描述设备读写、设备信息获取以及设备控制等外设操作,Guest OS对USB CDROM设备的IO操作通常基于SCSI命令实现,Guest OS下发IO操作到USB CDROM设备的通常流程是:
Guest OS将对设备的IO操作封装成SCSI命令,作为数据准备发送到CDROM设备 CDROM设备作为USB CDOM,它包含两方面特性: 首先该设备是大容量存储设备,其通信格式必须遵循USB Massive Storage Class Bulk-Only Transport协议,因此需要将SCSI命令作为Bulk-Only协议的payload,也即把SCSI命令封装成Bulk-Only协议格式的数据发送 其次该设备通过USB总线通信,因此需要确认目标设备在USB总线上的地址,找到其对应的USB控制器,将Bulk-Only协议格式的数据发送给控制器驱动,让控制器驱动程序按照USB协议格式再次封装,作为USB协议的payload发送到目标设备 目标USB设备(USBDevice)接收到数据,按照USB协议格式解析数据,取出其payload,也即Bulk-Only协议格式数据,转发给USB大容量存储设备 USB大容量存储设备(MSDState)收到转发数据后,按照Bulk-Only协议格式解释数据,取出其payload,也即SCSI命令,转发给CDROM设备 Guest OS对CDROM设备的IO操作基于SCSI命令,因此QEMU在模拟USB CDROM设备时,用SCSI设备代替CDROM设备,将其作为了MSDState的一个子模块,仅保持两者最终的存储介质相同。第4步数据到达MSDState,SCSI命令被提取后,实际上并非被真正的发送给了CDROM设备,而是发送给了代表CDROM设备的SCSI设备 SCSI设备按照SCSI协议解析得到要执行的IO操作,在命令行drive选项指定的存储介质中最终执行
上述流程参考示意图如下:
数据结构
static const TypeInfo usb_device_type_info = {.name = TYPE_USB_DEVICE,.parent = TYPE_DEVICE,.instance_size = sizeof(USBDevice),.instance_init = usb_device_instance_init,.abstract = true,.class_size = sizeof(USBDeviceClass),.class_init = usb_device_class_init,
};
static const TypeInfo usb_storage_dev_type_info = {.name = TYPE_USB_STORAGE,.parent = TYPE_USB_DEVICE,.instance_size = sizeof(MSDState),.abstract = true,.class_init = usb_msd_class_initfn_common,
};
static const TypeInfo msd_info = {.name = "usb-storage",.parent = TYPE_USB_STORAGE,.class_init = usb_msd_class_storage_initfn,.instance_init = usb_msd_instance_init,
};
设备实例化
UHCI
Frame List
TD
QH
SCSI