From mboxrd@z Thu Jan 1 00:00:00 1970 Received: from eggs.gnu.org ([208.118.235.92]:48162) by lists.gnu.org with esmtp (Exim 4.71) (envelope-from ) id 1TYIjB-00023X-KT for qemu-devel@nongnu.org; Tue, 13 Nov 2012 10:48:44 -0500 Received: from Debian-exim by eggs.gnu.org with spam-scanned (Exim 4.71) (envelope-from ) id 1TYIj8-0005ae-Hr for qemu-devel@nongnu.org; Tue, 13 Nov 2012 10:48:41 -0500 Received: from mail-vc0-f173.google.com ([209.85.220.173]:59574) by eggs.gnu.org with esmtp (Exim 4.71) (envelope-from ) id 1TYIj8-0005aH-CF for qemu-devel@nongnu.org; Tue, 13 Nov 2012 10:48:38 -0500 Received: by mail-vc0-f173.google.com with SMTP id fl15so7319097vcb.4 for ; Tue, 13 Nov 2012 07:48:37 -0800 (PST) Date: Tue, 13 Nov 2012 10:48:25 -0500 From: "Gabriel L. Somlo" Message-ID: <20121113154824.GA11399@hedwig.ini.cmu.edu> References: <20121111221650.GA3575@foober.ini.cmu.edu> <50A0CECA.9060102@redhat.com> <20121112151757.GB2107@hedwig.ini.cmu.edu> <50A2094A.3060500@redhat.com> MIME-Version: 1.0 Content-Type: text/plain; charset=us-ascii Content-Disposition: inline In-Reply-To: <50A2094A.3060500@redhat.com> Subject: Re: [Qemu-devel] q35, usb-ehci1, and Mac OS X boot problems List-Id: List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , To: Gerd Hoffmann Cc: rene@exactcode.com, jbaron@redhat.com, qemu-devel@nongnu.org, agraf@suse.de Gerd, On Tue, Nov 13, 2012 at 09:48:10AM +0100, Gerd Hoffmann wrote: > > below is what I got running the "-usb -device usb-kbd -device usb-mouse" > > command line with EHCI_DEBUG set to 1. > > This isn't what I ment. See docs/tracing.txt for how tracepoint work. > Wildcards (i.e. 'ehci_*') work on tracepoints. Below are the first 100 (of 6516784) ascii lines from the ehci_* trace file I collected in the cca. 30 seconds it took to get to the point where it's clear OS X boot is stuck and won't be making any further progress. In case you need it, the full (11M xz-compressed) trace file is at http://www.contrib.andrew.cmu.edu/~somlo/OSXKVM/ehci_trace.xz Thanks, --Gabriel usb_ehci_port_attach 0.000 port=0x0 owner=comp device=QEMU USB Keyboard usb_ehci_port_attach 31.297 port=0x1 owner=comp device=QEMU USB Mouse usb_ehci_reset 153537.179 usb_ehci_port_detach 1.689 port=0x0 owner=comp usb_ehci_port_detach 1.527 port=0x1 owner=comp usb_ehci_port_attach 1.311 port=0x0 owner=comp device=QEMU USB Keyboard usb_ehci_port_attach 2.506 port=0x1 owner=comp device=QEMU USB Mouse usb_ehci_opreg_read 338333.341 addr=0x20 str=USBCMD val=0x80000 usb_ehci_opreg_write 13.640 addr=0x20 str=USBCMD val=0x80002 usb_ehci_reset 1.018 usb_ehci_port_detach 1.546 port=0x0 owner=comp usb_ehci_port_detach 1.203 port=0x1 owner=comp usb_ehci_port_attach 1.669 port=0x0 owner=comp device=QEMU USB Keyboard usb_ehci_port_attach 3.504 port=0x1 owner=comp device=QEMU USB Mouse usb_ehci_opreg_change 2.038 addr=0x20 str=USBCMD new=0x80000 old=0x80000 usb_ehci_opreg_read 7.118 addr=0x20 str=USBCMD val=0x80000 usb_ehci_opreg_write 7.322 addr=0x28 str=USBINTR val=0x0 usb_ehci_opreg_change 0.699 addr=0x28 str=USBINTR new=0x0 old=0x0 usb_ehci_opreg_write 8.577 addr=0x34 str=P-LIST BASE val=0x7fffb000 usb_ehci_opreg_change 0.636 addr=0x34 str=P-LIST BASE new=0x7fffb000 old=0x0 usb_ehci_opreg_write 6.342 addr=0x38 str=A-LIST ADDR val=0x7fffc880 usb_ehci_opreg_change 0.498 addr=0x38 str=A-LIST ADDR new=0x7fffc880 old=0x0 usb_ehci_opreg_write 6.068 addr=0x20 str=USBCMD val=0x80031 usb_ehci_usbsts 4.793 sts=HALT state=0x0 usb_ehci_opreg_change 4.707 addr=0x20 str=USBCMD new=0x80031 old=0x80000 usb_ehci_opreg_write 53.414 addr=0x60 str=CONFIGFLAG val=0x1 usb_ehci_port_detach 1.060 port=0x0 owner=comp usb_ehci_port_attach 0.654 port=0x0 owner=ehci device=QEMU USB Keyboard usb_ehci_irq 0.654 level=0x0 frindex=0x0 sts=0x4 mask=0x0 usb_ehci_port_detach 0.965 port=0x1 owner=comp usb_ehci_port_attach 0.411 port=0x1 owner=ehci device=QEMU USB Mouse usb_ehci_irq 0.424 level=0x0 frindex=0x0 sts=0x4 mask=0x0 usb_ehci_opreg_change 0.664 addr=0x60 str=CONFIGFLAG new=0x1 old=0x0 usb_ehci_state 16.577 schedule=async state=ACTIVE usb_ehci_usbsts 1.527 sts=ASS state=0x1 usb_ehci_state 0.982 schedule=async state=WAITLISTHEAD usb_ehci_usbsts 1.143 sts=REC state=0x1 usb_ehci_qh_ptrs 5.108 q=0x0 addr=0x7fffc880 nxt=0x7fffc882 c_qtd=0x0 n_qtd=0x1 a_qtd=0x1 usb_ehci_qh_fields 0.599 addr=0x7fffc880 rl=0x0 mplen=0x0 eps=0x0 ep=0x0 devaddr=0x0 usb_ehci_qh_bits 0.607 addr=0x7fffc880 c=0x0 h=0x1 dtc=0x0 i=0x0 usb_ehci_state 0.792 schedule=async state=FETCH ENTRY usb_ehci_state 0.732 schedule=async state=FETCH QH usb_ehci_queue_action 4.098 q=0x7f358b3b0bd0 action=alloc usb_ehci_qh_ptrs 1.469 q=0x7f358b3b0bd0 addr=0x7fffc880 nxt=0x7fffc882 c_qtd=0x0 n_qtd=0x1 a_qtd=0x1 usb_ehci_qh_fields 0.531 addr=0x7fffc880 rl=0x0 mplen=0x0 eps=0x0 ep=0x0 devaddr=0x0 usb_ehci_qh_bits 0.494 addr=0x7fffc880 c=0x0 h=0x1 dtc=0x0 i=0x0 usb_ehci_queue_action 1.165 q=0x7f358b3b0bd0 action=reset usb_ehci_usbsts 0.933 sts=REC state=0x0 usb_ehci_state 0.579 schedule=async state=HORIZONTALQH usb_ehci_state 0.516 schedule=async state=ACTIVE usb_ehci_portsc_read 77.999 addr=0x44 port=0x0 val=0x1003 usb_ehci_portsc_read 24.851 addr=0x48 port=0x1 val=0x1003 usb_ehci_portsc_read 13.452 addr=0x4c port=0x2 val=0x1000 usb_ehci_portsc_read 9.878 addr=0x50 port=0x3 val=0x1000 usb_ehci_portsc_read 8.800 addr=0x54 port=0x4 val=0x1000 usb_ehci_portsc_read 8.715 addr=0x58 port=0x5 val=0x1000 usb_ehci_state 1799.380 schedule=periodic state=ACTIVE usb_ehci_usbsts 1.002 sts=PSS state=0x1 usb_ehci_state 2.575 schedule=periodic state=FETCH ENTRY usb_ehci_state 0.914 schedule=periodic state=FETCH QH usb_ehci_queue_action 2.116 q=0x7f358b3b0ed0 action=alloc usb_ehci_qh_ptrs 1.651 q=0x7f358b3b0ed0 addr=0x7fffc900 nxt=0x1 c_qtd=0x0 n_qtd=0x1 a_qtd=0x1 usb_ehci_qh_fields 0.612 addr=0x7fffc900 rl=0x0 mplen=0x0 eps=0x0 ep=0x0 devaddr=0x0 usb_ehci_qh_bits 0.584 addr=0x7fffc900 c=0x0 h=0x0 dtc=0x0 i=0x0 usb_ehci_queue_action 0.882 q=0x7f358b3b0ed0 action=reset usb_ehci_state 0.710 schedule=periodic state=HORIZONTALQH usb_ehci_state 0.526 schedule=periodic state=FETCH ENTRY usb_ehci_state 0.519 schedule=periodic state=ACTIVE usb_ehci_state 0.694 schedule=periodic state=FETCH ENTRY usb_ehci_state 0.441 schedule=periodic state=FETCH QH usb_ehci_qh_ptrs 1.454 q=0x7f358b3b0ed0 addr=0x7fffc900 nxt=0x1 c_qtd=0x0 n_qtd=0x1 a_qtd=0x1 usb_ehci_qh_fields 0.544 addr=0x7fffc900 rl=0x0 mplen=0x0 eps=0x0 ep=0x0 devaddr=0x0 usb_ehci_qh_bits 0.504 addr=0x7fffc900 c=0x0 h=0x0 dtc=0x0 i=0x0 usb_ehci_state 0.579 schedule=periodic state=HORIZONTALQH usb_ehci_state 0.408 schedule=periodic state=FETCH ENTRY usb_ehci_state 0.424 schedule=periodic state=ACTIVE usb_ehci_state 0.604 schedule=async state=WAITLISTHEAD usb_ehci_usbsts 0.604 sts=REC state=0x1 usb_ehci_qh_ptrs 1.581 q=0x0 addr=0x7fffc880 nxt=0x7fffc882 c_qtd=0x0 n_qtd=0x1 a_qtd=0x1 usb_ehci_qh_fields 0.539 addr=0x7fffc880 rl=0x0 mplen=0x0 eps=0x0 ep=0x0 devaddr=0x0 usb_ehci_qh_bits 0.529 addr=0x7fffc880 c=0x0 h=0x1 dtc=0x0 i=0x0 usb_ehci_state 0.539 schedule=async state=FETCH ENTRY usb_ehci_state 0.504 schedule=async state=FETCH QH usb_ehci_qh_ptrs 1.591 q=0x7f358b3b0bd0 addr=0x7fffc880 nxt=0x7fffc882 c_qtd=0x0 n_qtd=0x1 a_qtd=0x1 usb_ehci_qh_fields 0.537 addr=0x7fffc880 rl=0x0 mplen=0x0 eps=0x0 ep=0x0 devaddr=0x0 usb_ehci_qh_bits 7.033 addr=0x7fffc880 c=0x0 h=0x1 dtc=0x0 i=0x0 usb_ehci_usbsts 0.714 sts=REC state=0x0 usb_ehci_state 0.358 schedule=async state=HORIZONTALQH usb_ehci_state 0.509 schedule=async state=ACTIVE usb_ehci_state 3983.812 schedule=periodic state=FETCH ENTRY usb_ehci_state 1.120 schedule=periodic state=FETCH QH usb_ehci_qh_ptrs 1.860 q=0x7f358b3b0ed0 addr=0x7fffc900 nxt=0x1 c_qtd=0x0 n_qtd=0x1 a_qtd=0x1 usb_ehci_qh_fields 0.752 addr=0x7fffc900 rl=0x0 mplen=0x0 eps=0x0 ep=0x0 devaddr=0x0 usb_ehci_qh_bits 0.614 addr=0x7fffc900 c=0x0 h=0x0 dtc=0x0 i=0x0 usb_ehci_state 0.985 schedule=periodic state=HORIZONTALQH usb_ehci_state 0.514 schedule=periodic state=FETCH ENTRY usb_ehci_state 0.569 schedule=periodic state=ACTIVE usb_ehci_state 0.629 schedule=periodic state=FETCH ENTRY usb_ehci_state 0.408 schedule=periodic state=FETCH QH usb_ehci_qh_ptrs 1.424 q=0x7f358b3b0ed0 addr=0x7fffc900 nxt=0x1 c_qtd=0x0 n_qtd=0x1 a_qtd=0x1