Re: [Qemu-devel] xhci migration breakage

["Dr. David Alan Gilbert" <dgilbert@redhat.com>]

* Gerd Hoffmann (kraxel@redhat.com) wrote:
>   Hi,
> 
> > I guess maybe there's a kick needed pre/post migrate?
> 
> Sure, but it is there already (post_load arms kick_timer for active
> endpoints), so it isn't *that* simple.
> 
> Looking at this I have no idea offhand, guess I have to schedule some
> debugging for tomorrow.  Keep me posted in case you continue digging.

OK, I don't know any of this code, but my poking about so far is:

source
....
xhci: setup packet pid 0x69 addr 1 ep 1
20095@1490894271.183259:usb_xhci_ep_kick slotid 1, epid 4, streamid 0
xhci: set epctx: 35497080 state=1 dequeue=0000000230cf2f61
20095@1490894271.183284:usb_xhci_xfer_start 0x7f302931fef0: slotid 1, epid 4, streamid 0
xhci_submit(slotid=1,epid=4)
xhci: setup packet pid 0xe1 addr 1 ep 2
20095@1490894271.183404:usb_xhci_ep_kick slotid 1, epid 3, streamid 0
xhci: set epctx: 35497060 state=1 dequeue=0000000230cf3331
20095@1490894271.183420:usb_xhci_xfer_start 0x7f302931fef0: slotid 1, epid 3, streamid 0
xhci_submit(slotid=1,epid=3)
xhci: setup packet pid 0x69 addr 1 ep 1
inputs_connect: inputs channel client create
red_dispatcher_set_cursor_peer: 

(qemu) migra
migrate                 migrate_cancel          migrate_incoming        
migrate_set_cache_size  migrate_set_capability  migrate_set_downtime    
migrate_set_parameter   migrate_set_speed       migrate_start_postcopy  
(qemu) migrate_set_speed 1G
(qemu) migrate tcp:0:4444
usb-storage msd pre_save 0x7f3044627960 sig=0 tag=0
(qemu) q

dest:
(qemu) red_dispatcher_loadvm_commands: 
usb-storage msd post_load 0x7f45f510ee50 sig=0 tag=0

I added these as debug on the 'usb-storage' vmsd element; but
the signature/tag being 0 I assume they're not the culprit.

(qemu) c
(qemu) 20107@1490894287.479732:usb_xhci_ep_kick slotid 1, epid 1, streamid 0
xhci: set epctx: 35497020 state=1 dequeue=0000000035499231
20107@1490894287.479763:usb_xhci_xfer_start 0x7f45f556a800: slotid 1, epid 1, streamid 0
xhci: setup packet pid 0x69 addr 1 ep 0
20107@1490894287.479799:usb_xhci_ep_kick slotid 1, epid 3, streamid 0
xhci: set epctx: 35497060 state=1 dequeue=0000000230cf3331
20107@1490894287.479812:usb_xhci_xfer_start 0x7f45f556a800: slotid 1, epid 3, streamid 0
xhci_submit(slotid=1,epid=3)
xhci: setup packet pid 0x69 addr 1 ep 1
xhci: set epctx: 35497060 state=2 dequeue=0000000230cf3331
20107@1490894287.479837:usb_xhci_ep_kick slotid 1, epid 4, streamid 0
xhci: set epctx: 35497080 state=1 dequeue=0000000230cf2f61
20107@1490894287.479848:usb_xhci_xfer_start 0x7f45f556a800: slotid 1, epid 4, streamid 0
xhci_submit(slotid=1,epid=4)
xhci: setup packet pid 0xe1 addr 1 ep 2
qemu-system-x86_64: usb-msd: Bad signature 53425300

given the bottom byte is 0 - is anything supposed to poison these things when
they're finished with them?


The backtrace (where I added an assert) shows it is coming off the timer
(Note I think this is a different run from that above):
#3  0x00007feba72c91f2 in __GI___assert_fail (assertion=assertion@entry=0x7febabcc1f3a "0", file=file@entry=0x7febabcb1f90 "/root/1436616/qemu/hw/usb/dev-storage.c", line=line@entry=429, function=function@entry=0x7febabcb20f0 <__PRETTY_FUNCTION__.30660> "usb_msd_handle_data") at assert.c:101
#4  0x00007febabad00e1 in usb_msd_handle_data (dev=0x7febae693e50, p=0x7febaeaef808)
    at /root/1436616/qemu/hw/usb/dev-storage.c:429
#5  0x00007febabab2b58 in usb_handle_packet (dev=<optimized out>, p=p@entry=0x7febaeaef808)
    at /root/1436616/qemu/hw/usb/core.c:412
#6  0x00007febabacae27 in xhci_kick_epctx (epctx=<optimized out>, xfer=<optimized out>, xhci=<optimized out>)
    at /root/1436616/qemu/hw/usb/hcd-xhci.c:2103 <- right at the end of xhci_submit
#7  0x00007febabacae27 in xhci_kick_epctx (epctx=<optimized out>, xfer=<optimized out>, xhci=<optimized out>)
    at /root/1436616/qemu/hw/usb/hcd-xhci.c:2112 right at end of xhci_fire_transfer
#8  0x00007febabacae27 in xhci_kick_epctx (epctx=0x7febaec395a0, streamid=0)
    at /root/1436616/qemu/hw/usb/hcd-xhci.c:2240
#9  0x00007febabb4c8b9 in timerlist_run_timers (timer_list=0x7febad2ad790) at /root/1436616/qemu/qemu-timer.c:540
#10 0x00007febabb4cb20 in qemu_clock_run_all_timers (type=<optimized out>) at /root/1436616/qemu/qemu-timer.c:551
#11 0x00007febabb4cb20 in qemu_clock_run_all_timers () at /root/1436616/qemu/qemu-timer.c:665
#12 0x00007febabb4bae7 in main_loop_wait (nonblocking=<optimized out>) at /root/1436616/qemu/main-loop.c:516
#13 0x00007febab8855e2 in main () at /root/1436616/qemu/vl.c:1888
#14 0x00007febab8855e2 in main (argc=<optimized out>, argv=<optimized out>, envp=<optimized out>)
    at /root/1436616/qemu/vl.c:4630

Dave

> cheers,
>   Gerd
> 
--
Dr. David Alan Gilbert / dgilbert@redhat.com / Manchester, UK