From patchwork Fri Aug 17 06:31:44 2012 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: Hans de Goede X-Patchwork-Id: 178143 Return-Path: X-Original-To: incoming@patchwork.ozlabs.org Delivered-To: patchwork-incoming@bilbo.ozlabs.org Received: from lists.gnu.org (lists.gnu.org [208.118.235.17]) (using TLSv1 with cipher AES256-SHA (256/256 bits)) (Client did not present a certificate) by ozlabs.org (Postfix) with ESMTPS id 8F5A32C0090 for ; Fri, 17 Aug 2012 16:30:59 +1000 (EST) Received: from localhost ([::1]:55271 helo=lists.gnu.org) by lists.gnu.org with esmtp (Exim 4.71) (envelope-from ) id 1T2G5B-0002zx-Dp for incoming@patchwork.ozlabs.org; Fri, 17 Aug 2012 02:30:57 -0400 Received: from eggs.gnu.org ([208.118.235.92]:57524) by lists.gnu.org with esmtp (Exim 4.71) (envelope-from ) id 1T2G50-0002zs-Me for qemu-devel@nongnu.org; Fri, 17 Aug 2012 02:30:48 -0400 Received: from Debian-exim by eggs.gnu.org with spam-scanned (Exim 4.71) (envelope-from ) id 1T2G4y-0007F7-0U for qemu-devel@nongnu.org; Fri, 17 Aug 2012 02:30:46 -0400 Received: from mx1.redhat.com ([209.132.183.28]:37441) by eggs.gnu.org with esmtp (Exim 4.71) (envelope-from ) id 1T2G4x-0007Br-NE for qemu-devel@nongnu.org; Fri, 17 Aug 2012 02:30:43 -0400 Received: from int-mx10.intmail.prod.int.phx2.redhat.com (int-mx10.intmail.prod.int.phx2.redhat.com [10.5.11.23]) by mx1.redhat.com (8.14.4/8.14.4) with ESMTP id q7H6Ugpx019880 (version=TLSv1/SSLv3 cipher=DHE-RSA-AES256-SHA bits=256 verify=OK) for ; Fri, 17 Aug 2012 02:30:42 -0400 Received: from shalem.localdomain (vpn1-6-22.ams2.redhat.com [10.36.6.22]) by int-mx10.intmail.prod.int.phx2.redhat.com (8.14.4/8.14.4) with ESMTP id q7H6Udto027847 (version=TLSv1/SSLv3 cipher=DHE-RSA-CAMELLIA256-SHA bits=256 verify=NO); Fri, 17 Aug 2012 02:30:40 -0400 Message-ID: <502DE550.90503@redhat.com> Date: Fri, 17 Aug 2012 08:31:44 +0200 From: Hans de Goede User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:14.0) Gecko/20120717 Thunderbird/14.0 MIME-Version: 1.0 To: Gerd Hoffmann References: <502A78D9.6050003@redhat.com> <502CF9BB.8020107@redhat.com> <502D4961.3060300@redhat.com> In-Reply-To: <502D4961.3060300@redhat.com> X-Scanned-By: MIMEDefang 2.68 on 10.5.11.23 X-detected-operating-system: by eggs.gnu.org: Genre and OS details not recognized. X-Received-From: 209.132.183.28 Cc: "qemu-devel@nongnu.org" Subject: Re: [Qemu-devel] 2 issues with qemu-master / 1.2 ehci code X-BeenThere: qemu-devel@nongnu.org X-Mailman-Version: 2.1.14 Precedence: list List-Id: List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Errors-To: qemu-devel-bounces+incoming=patchwork.ozlabs.org@nongnu.org Sender: qemu-devel-bounces+incoming=patchwork.ozlabs.org@nongnu.org Hi, On 08/16/2012 09:26 PM, Gerd Hoffmann wrote: >> I can get things working by turning ehci_fill_queue() into a nop... >> Investigating this further. But if you've any insights they would be >> appreciated. I'm thinking this may be caused by packets completing >> out of order, which could be caused by the special handling of some >> ctrl commands ... > > usbredir wouldn't see multiple parallel inflight requests per endpoint > unless you explicitly enable this using usb_ep_set_pipeline(). Doing > that on bulk endpoints should give you a nice performance boost for usb > sticks. Doing it on the control endpoint is asking for trouble ;) > > Can you turn on all ehci tracepoints & send me a log? No need for that, I've been debugging this almost the entire day yesterday and I've significantly narrowed it down further, the problem is that the assert triggers when: 1) There are more packets then 1 in the queue (iow fill_queue did something) 2) A packet completion is not followed by an advqueue call 2) happens when a packet fails, and the queue should be halted, in this case ehci_state_writeback() correctly does not call advqueue, bot does a horizqh instead. The problem is that once this happens p->qtdaddr == q->qtdaddr is no longer true ... I've already come up with multiple approaches to try and fix this, but none work sofar :| Another problem with failing packets is that hw/usb/core.c will happily execute the next packet in the ep queue, even though the spec says the ep-queue should be halted, giving the guest a chance to cancel transfers after the failed one without them ever executing. I've a poc patch fixing this too. I've attached a wip patch with my work on this so-far. Note that currently the halted bit at the ehci level never gets cleared (since we've queues at 2 levels, we need to track halting at 2 levels too) Regards, Hans diff --git a/hw/usb.h b/hw/usb.h index 432ccae..6fa3088 100644 --- a/hw/usb.h +++ b/hw/usb.h @@ -179,6 +179,7 @@ struct USBEndpoint { uint8_t ifnum; int max_packet_size; bool pipeline; + bool halted; USBDevice *dev; QTAILQ_HEAD(, USBPacket) queue; }; @@ -375,6 +376,8 @@ void usb_ep_set_max_packet_size(USBDevice *dev, int pid, int ep, uint16_t raw); int usb_ep_get_max_packet_size(USBDevice *dev, int pid, int ep); void usb_ep_set_pipeline(USBDevice *dev, int pid, int ep, bool enabled); +void usb_ep_process_queue(USBEndpoint *ep); +void usb_ep_clear_halt(USBEndpoint *ep); void usb_attach(USBPort *port); void usb_detach(USBPort *port); diff --git a/hw/usb/core.c b/hw/usb/core.c index c7e5bc0..c9ad57e 100644 --- a/hw/usb/core.c +++ b/hw/usb/core.c @@ -382,12 +382,20 @@ int usb_handle_packet(USBDevice *dev, USBPacket *p) usb_packet_check_state(p, USB_PACKET_SETUP); assert(p->ep != NULL); + /* Submitting a new packet clears halt */ + p->ep->halted = false; + if (QTAILQ_EMPTY(&p->ep->queue) || p->ep->pipeline) { ret = usb_process_one(p); if (ret == USB_RET_ASYNC) { usb_packet_set_state(p, USB_PACKET_ASYNC); QTAILQ_INSERT_TAIL(&p->ep->queue, p, queue); } else { + /* + * When pipelining is enabled usb-devices must always return async, + * otherwise packets can complete out of order! + */ + assert(!p->ep->pipeline); p->result = ret; usb_packet_set_state(p, USB_PACKET_COMPLETE); } @@ -402,33 +410,26 @@ int usb_handle_packet(USBDevice *dev, USBPacket *p) /* Notify the controller that an async packet is complete. This should only be called for packets previously deferred by returning USB_RET_ASYNC from handle_packet. */ -void usb_packet_complete(USBDevice *dev, USBPacket *p) +static void __usb_packet_complete(USBDevice *dev, USBPacket *p) { USBEndpoint *ep = p->ep; - int ret; - usb_packet_check_state(p, USB_PACKET_ASYNC); - assert(QTAILQ_FIRST(&ep->queue) == p); + if (p->result < 0) { +// ep->halted = true; + } usb_packet_set_state(p, USB_PACKET_COMPLETE); QTAILQ_REMOVE(&ep->queue, p, queue); dev->port->ops->complete(dev->port, p); +} - while (!QTAILQ_EMPTY(&ep->queue)) { - p = QTAILQ_FIRST(&ep->queue); - if (p->state == USB_PACKET_ASYNC) { - break; - } - usb_packet_check_state(p, USB_PACKET_QUEUED); - ret = usb_process_one(p); - if (ret == USB_RET_ASYNC) { - usb_packet_set_state(p, USB_PACKET_ASYNC); - break; - } - p->result = ret; - usb_packet_set_state(p, USB_PACKET_COMPLETE); - QTAILQ_REMOVE(&ep->queue, p, queue); - dev->port->ops->complete(dev->port, p); - } +void usb_packet_complete(USBDevice *dev, USBPacket *p) +{ + USBEndpoint *ep = p->ep; + + usb_packet_check_state(p, USB_PACKET_ASYNC); + assert(QTAILQ_FIRST(&ep->queue) == p); + __usb_packet_complete(dev, p); + usb_ep_process_queue(ep); } /* Cancel an active packet. The packed must have been deferred by @@ -702,3 +703,30 @@ void usb_ep_set_pipeline(USBDevice *dev, int pid, int ep, bool enabled) struct USBEndpoint *uep = usb_ep_get(dev, pid, ep); uep->pipeline = enabled; } + +void usb_ep_process_queue(USBEndpoint *ep) +{ + USBPacket *p; + int ret; + + while (!ep->halted && !QTAILQ_EMPTY(&ep->queue)) { + p = QTAILQ_FIRST(&ep->queue); + if (p->state == USB_PACKET_ASYNC) { + break; + } + usb_packet_check_state(p, USB_PACKET_QUEUED); + ret = usb_process_one(p); + if (ret == USB_RET_ASYNC) { + usb_packet_set_state(p, USB_PACKET_ASYNC); + break; + } + p->result = ret; + __usb_packet_complete(ep->dev, p); + } +} + +void usb_ep_clear_halt(USBEndpoint *ep) +{ + ep->halted = false; + usb_ep_process_queue(ep); +} diff --git a/hw/usb/hcd-ehci.c b/hw/usb/hcd-ehci.c index 41d663d..c8d2d96 100644 --- a/hw/usb/hcd-ehci.c +++ b/hw/usb/hcd-ehci.c @@ -366,6 +366,7 @@ struct EHCIQueue { uint64_t ts; int async; int revalidate; + bool halted; /* cached data from guest - needs to be flushed * when guest removes an entry (doorbell, handshake sequence) @@ -740,6 +741,7 @@ static EHCIPacket *ehci_alloc_packet(EHCIQueue *q) static void ehci_free_packet(EHCIPacket *p) { + printf("queue %p packet %p free\n", p->queue, p); trace_usb_ehci_packet_action(p->queue, p, "free"); if (p->async == EHCI_ASYNC_INFLIGHT) { usb_cancel_packet(&p->packet); @@ -1773,6 +1775,7 @@ static EHCIQueue *ehci_state_fetchqh(EHCIState *ehci, int async) if (q->revalidate && (q->qh.epchar != qh.epchar || q->qh.epcap != qh.epcap || q->qh.current_qtd != qh.current_qtd)) { + printf("queue %p packet %p qtdaddr %08x freeing because of cancel\n", q, NULL, q->qtdaddr); ehci_free_queue(q); q = ehci_alloc_queue(ehci, entry, async); q->seen++; @@ -1786,6 +1789,7 @@ static EHCIQueue *ehci_state_fetchqh(EHCIState *ehci, int async) if (q->dev != NULL && q->dev->addr != devaddr) { if (!QTAILQ_EMPTY(&q->packets)) { /* should not happen (guest bug) */ + printf("guest bug 2!!!\n"); while ((p = QTAILQ_FIRST(&q->packets)) != NULL) { ehci_free_packet(p); } @@ -1796,18 +1800,22 @@ static EHCIQueue *ehci_state_fetchqh(EHCIState *ehci, int async) q->dev = ehci_find_device(q->ehci, devaddr); } - if (p && p->async == EHCI_ASYNC_INFLIGHT) { + if (!q->halted && p && p->async == EHCI_ASYNC_INFLIGHT) { +// if (p->packet.ep->halted && !(q->qh.token & QTD_TOKEN_HALT)) { +// usb_ep_clear_halt(p->packet.ep); +// } /* I/O still in progress -- skip queue */ ehci_set_state(ehci, async, EST_HORIZONTALQH); goto out; } - if (p && p->async == EHCI_ASYNC_FINISHED) { + if (!q->halted && p && p->async == EHCI_ASYNC_FINISHED) { /* I/O finished -- continue processing queue */ trace_usb_ehci_packet_action(p->queue, p, "complete"); + if ((q->qh.epchar & QH_EPCHAR_EP_MASK) == 0) + printf("queue %p packet %p qtdaddr %08x completing from fetchqh\n", q, p, p->qtdaddr); ehci_set_state(ehci, async, EST_EXECUTING); goto out; } - if (async && (q->qh.epchar & QH_EPCHAR_H)) { /* EHCI spec version 1.0 Section 4.8.3 & 4.10.1 */ @@ -1842,6 +1850,8 @@ static EHCIQueue *ehci_state_fetchqh(EHCIState *ehci, int async) ehci_set_state(ehci, async, EST_FETCHQTD); } else { + if ((q->qh.epchar & QH_EPCHAR_EP_MASK) == 0) + printf("queue %p packet %p qtdaddr %08x advqueue fetchqh\n", q, NULL, q->qtdaddr); /* EHCI spec version 1.0 Section 4.10.2 */ ehci_set_state(ehci, async, EST_ADVANCEQUEUE); } @@ -1951,19 +1961,31 @@ static int ehci_state_fetchqtd(EHCIQueue *q) p = QTAILQ_FIRST(&q->packets); while (p != NULL && p->qtdaddr != q->qtdaddr) { /* should not happen (guest bug) */ + printf("guest bug!!!\n"); ehci_free_packet(p); p = QTAILQ_FIRST(&q->packets); } if (p != NULL) { ehci_qh_do_overlay(q); - if (p->async == EHCI_ASYNC_INFLIGHT) { + switch (p->async) { + case EHCI_ASYNC_NONE: + ehci_set_state(q->ehci, q->async, EST_EXECUTING); + break; + case EHCI_ASYNC_INFLIGHT: ehci_set_state(q->ehci, q->async, EST_HORIZONTALQH); - } else { + break; + case EHCI_ASYNC_FINISHED: + trace_usb_ehci_packet_action(q, p, "complete"); + if ((q->qh.epchar & QH_EPCHAR_EP_MASK) == 0) + printf("queue %p packet %p qtdaddr %08x completing from fetchqtd\n", q, p, p->qtdaddr); ehci_set_state(q->ehci, q->async, EST_EXECUTING); + break; } again = 1; } else if (qtd.token & QTD_TOKEN_ACTIVE) { p = ehci_alloc_packet(q); + if ((q->qh.epchar & QH_EPCHAR_EP_MASK) == 0) + printf("queue %p packet %p qtdaddr %08x ep %d added (fetchqtd)\n", q, p, q->qtdaddr, (q->qh.epchar & QH_EPCHAR_EP_MASK) >> QH_EPCHAR_EP_SH); p->qtdaddr = q->qtdaddr; p->qtd = qtd; ehci_set_state(q->ehci, q->async, EST_EXECUTE); @@ -2012,6 +2034,8 @@ static void ehci_fill_queue(EHCIPacket *p) break; } p = ehci_alloc_packet(q); + if ((q->qh.epchar & QH_EPCHAR_EP_MASK) == 0) + printf("queue %p packet %p qtdaddr %08x added (fill_queue)\n", q, p, qtdaddr); p->qtdaddr = qtdaddr; p->qtd = qtd; p->usb_status = ehci_execute(p, "queue"); @@ -2076,10 +2100,15 @@ static int ehci_state_executing(EHCIQueue *q) EHCIPacket *p = QTAILQ_FIRST(&q->packets); int again = 0; + if ((q->qh.epchar & QH_EPCHAR_EP_MASK) == 0) + printf("queue %p packet %p qtdaddr %08x completing, async %d\n", q, p, p->qtdaddr, p->async); + assert(p != NULL); assert(p->qtdaddr == q->qtdaddr); ehci_execute_complete(q); + if ((q->qh.epchar & QH_EPCHAR_EP_MASK) == 0) + printf("queue %p packet %p qtdaddr %08x completed, status %d\n", q, p, p->qtdaddr, p->usb_status); if (p->usb_status == USB_RET_ASYNC) { goto out; } @@ -2137,6 +2166,7 @@ static int ehci_state_writeback(EHCIQueue *q) * bit is clear. */ if (q->qh.token & QTD_TOKEN_HALT) { + q->halted = true; ehci_set_state(q->ehci, q->async, EST_HORIZONTALQH); again = 1; } else {