{"id":2228019,"url":"http://patchwork.ozlabs.org/api/1.1/patches/2228019/?format=json","web_url":"http://patchwork.ozlabs.org/project/qemu-devel/patch/20260424192543.22614-11-philmd@linaro.org/","project":{"id":14,"url":"http://patchwork.ozlabs.org/api/1.1/projects/14/?format=json","name":"QEMU Development","link_name":"qemu-devel","list_id":"qemu-devel.nongnu.org","list_email":"qemu-devel@nongnu.org","web_url":"","scm_url":"","webscm_url":""},"msgid":"<20260424192543.22614-11-philmd@linaro.org>","date":"2026-04-24T19:25:42","name":"[PULL,v4,54/62] hw/usb/hcd-ehci: Replace DPRINTF debug logs with trace events","commit_ref":null,"pull_url":null,"state":"new","archived":false,"hash":"9b76643968f0cc9912afe985d74fbebfb3fc9f54","submitter":{"id":85046,"url":"http://patchwork.ozlabs.org/api/1.1/people/85046/?format=json","name":"Philippe Mathieu-Daudé","email":"philmd@linaro.org"},"delegate":null,"mbox":"http://patchwork.ozlabs.org/project/qemu-devel/patch/20260424192543.22614-11-philmd@linaro.org/mbox/","series":[{"id":501401,"url":"http://patchwork.ozlabs.org/api/1.1/series/501401/?format=json","web_url":"http://patchwork.ozlabs.org/project/qemu-devel/list/?series=501401","date":"2026-04-24T19:25:34","name":null,"version":4,"mbox":"http://patchwork.ozlabs.org/series/501401/mbox/"}],"comments":"http://patchwork.ozlabs.org/api/patches/2228019/comments/","check":"pending","checks":"http://patchwork.ozlabs.org/api/patches/2228019/checks/","tags":{},"headers":{"Return-Path":"","X-Original-To":"incoming@patchwork.ozlabs.org","Delivered-To":"patchwork-incoming@legolas.ozlabs.org","Authentication-Results":["legolas.ozlabs.org;\n\tdkim=pass (2048-bit key;\n unprotected) header.d=linaro.org header.i=@linaro.org header.a=rsa-sha256\n header.s=google header.b=PLX87zMd;\n\tdkim-atps=neutral","legolas.ozlabs.org;\n spf=pass (sender SPF authorized) smtp.mailfrom=nongnu.org\n (client-ip=209.51.188.17; helo=lists1p.gnu.org;\n envelope-from=qemu-devel-bounces+incoming=patchwork.ozlabs.org@nongnu.org;\n receiver=patchwork.ozlabs.org)"],"Received":["from lists1p.gnu.org (lists1p.gnu.org [209.51.188.17])\n\t(using TLSv1.2 with cipher ECDHE-ECDSA-AES256-GCM-SHA384 (256/256 bits))\n\t(No client certificate requested)\n\tby legolas.ozlabs.org (Postfix) with ESMTPS id 4g2NJW5XSKz1y2d\n\tfor ; Sat, 25 Apr 2026 05:27:23 +1000 (AEST)","from localhost ([::1] helo=lists1p.gnu.org)\n\tby lists1p.gnu.org with esmtp (Exim 4.90_1)\n\t(envelope-from )\n\tid 1wGMB4-0005Pa-7Z; Fri, 24 Apr 2026 15:27:02 -0400","from eggs.gnu.org ([2001:470:142:3::10])\n by lists1p.gnu.org with esmtps (TLS1.2:ECDHE_RSA_AES_256_GCM_SHA384:256)\n (Exim 4.90_1) (envelope-from ) id 1wGMB1-000556-W3\n for qemu-devel@nongnu.org; Fri, 24 Apr 2026 15:27:00 -0400","from mail-wm1-x32b.google.com ([2a00:1450:4864:20::32b])\n by eggs.gnu.org with esmtps (TLS1.2:ECDHE_RSA_AES_128_GCM_SHA256:128)\n (Exim 4.90_1) (envelope-from ) id 1wGMAz-0001hF-FV\n for qemu-devel@nongnu.org; Fri, 24 Apr 2026 15:26:59 -0400","by mail-wm1-x32b.google.com with SMTP id\n 5b1f17b1804b1-48984d29fe3so90757515e9.0\n for ; Fri, 24 Apr 2026 12:26:57 -0700 (PDT)","from localhost.localdomain (88-187-86-199.subs.proxad.net.\n [88.187.86.199]) by smtp.gmail.com with ESMTPSA id\n 5b1f17b1804b1-488fb7b2716sm191911485e9.30.2026.04.24.12.26.53\n for \n (version=TLS1_3 cipher=TLS_CHACHA20_POLY1305_SHA256 bits=256/256);\n Fri, 24 Apr 2026 12:26:53 -0700 (PDT)"],"DKIM-Signature":"v=1; a=rsa-sha256; c=relaxed/relaxed;\n d=linaro.org; s=google; t=1777058815; x=1777663615; darn=nongnu.org;\n h=content-transfer-encoding:mime-version:references:in-reply-to\n :message-id:date:subject:to:from:from:to:cc:subject:date:message-id\n :reply-to; bh=RxfzJlmuo8tmdqUwHdWNSQl/LrnZoeealET/va5hRPU=;\n b=PLX87zMdVytnvUnsgvW7WHAif3rzp7pRTXNR/w9i3rcC0LdZ4ZRdf6bFiliGUGmQ5L\n zjfrVz3zSVvTboRx0EWAdfL38wMRPrt/l3E76uBds0IugVBbNxYUF4VdE54SfaqxoLvE\n 05R6LiSep79xMuIiXVpLv7d8Bma2A72zFBuWxvkAzqgEHuhI09xT+2GJb/ONo7RvFoob\n /Iv6l3CdMOJGqTfjeQZBO6ftEX/ygqi9gTpbMUxaU5idmWlOhDoqYcbgd3+NWX5w4P6S\n Yt2RpDQ7W31nCzG+LpZoIhelF8iHkJr08ejBHEfJ8nG/gjKfyNLo+60WxsRoTzo+ReD9\n cDJg==","X-Google-DKIM-Signature":"v=1; a=rsa-sha256; c=relaxed/relaxed;\n d=1e100.net; s=20251104; t=1777058815; x=1777663615;\n h=content-transfer-encoding:mime-version:references:in-reply-to\n :message-id:date:subject:to:from:x-gm-gg:x-gm-message-state:from:to\n :cc:subject:date:message-id:reply-to;\n bh=RxfzJlmuo8tmdqUwHdWNSQl/LrnZoeealET/va5hRPU=;\n b=NEX0sGMc3DhZdhTSDDKGV5rU0TshKgLXU/IqE1Gq33dDdHaYVO0O50EE+Y9HPba1uB\n hJtk3QkeXMAqghJUqPkmrNWhMts16h7QIaUKsZF1mkECbJ6ppZp5sKvVftxJRpDiECOV\n FXZo+kQ8gQiUZX+zqsXTXjuXMzMLs1mkSObOI0W1N1yeoMlotdIYo58tMdplWUWLCst4\n ite6u7sCNcKK2ioV6qRQ49hLOQTM3+IuIAqd62lnn7ycpX+ISpxyGY/+Z8Umu+68hHaz\n 2YgeCpyI+vw7YJbLL+8wQBJS91WQctk4DlgBAk1NzRE4YdApNvEQ7nqLeKMWPNSl3qak\n lF9A==","X-Gm-Message-State":"AOJu0YxUmESm/GUr8KC8nhAJdqCHDMz7F1KG/MJJm0nc8mND+YzRTKqI\n 7O2UAelaB0GQjdwMDkqWpeJ4+RDYT/qmEP9pXDlb69SakAfM3zZXjFOtrvtlF53++9Mmf3w7MCh\n 3lZIPuhU=","X-Gm-Gg":"AeBDievO3wcY9h7XMz+GBjyK/zlsertQWva5SuT4uACZFFPi0kXd+nYZdlb5xgL5d9m\n D+Yrj3CIlX+PZDDeHOqlF/crc87NmWQO+PNOzYqfM7vofhT4z3plMgdsAdsz760HcA7ad3bgQVy\n uQF9iBQkdoBJ2eytQZBrJpqhYzHK12tHuRTSx2j8TmFOEASDBoQZG8tNgKrr/BsVapNxh2UjEKc\n c1Eloa8EzZGAs7cA8Ygj17BeGFj2bIrG2xy/wqQpKvg9+h1KhjBBpSGY0azck/fCuhVsXiIhaXK\n iFRUKulZxjhYkgTpyWwHnXEOnjf5MXkI9TmRJ8aqe0vqbPNoTvBeAclTXhfZybnrjH5pQRam5fg\n MBKRvfGDFBKf2hiFIZh61QtQ0zS3J0ypIMuGtQwPqrzTiuCBdwh1cTzVfJ90apsvqn4zPDCQ00C\n b/4IbgLLQScPka7dOW5OPCNFaN3dTZGvQfeB5VrHIAhU4FptGa20dDoOaGJ8b1TN1PX+OtHI+Tc\n dMSGXVqisaYxCcDHIJF+w==","X-Received":"by 2002:a05:600c:797:b0:489:1a3a:9e45 with SMTP id\n 5b1f17b1804b1-4891a3a9f38mr213736915e9.26.1777058815231;\n Fri, 24 Apr 2026 12:26:55 -0700 (PDT)","From":"=?utf-8?q?Philippe_Mathieu-Daud=C3=A9?= ","To":"qemu-devel@nongnu.org","Subject":"[PULL v4 54/62] hw/usb/hcd-ehci: Replace DPRINTF debug logs with\n trace events","Date":"Fri, 24 Apr 2026 21:25:42 +0200","Message-ID":"<20260424192543.22614-11-philmd@linaro.org>","X-Mailer":"git-send-email 2.53.0","In-Reply-To":"<20260424192543.22614-1-philmd@linaro.org>","References":"<20260424192543.22614-1-philmd@linaro.org>","MIME-Version":"1.0","Content-Type":"text/plain; charset=UTF-8","Content-Transfer-Encoding":"8bit","Received-SPF":"pass client-ip=2a00:1450:4864:20::32b;\n envelope-from=philmd@linaro.org; helo=mail-wm1-x32b.google.com","X-Spam_score_int":"-20","X-Spam_score":"-2.1","X-Spam_bar":"--","X-Spam_report":"(-2.1 / 5.0 requ) BAYES_00=-1.9, DKIM_SIGNED=0.1,\n DKIM_VALID=-0.1, DKIM_VALID_AU=-0.1, DKIM_VALID_EF=-0.1,\n RCVD_IN_DNSWL_NONE=-0.0001, SPF_HELO_NONE=0.001,\n SPF_PASS=-0.001 autolearn=ham autolearn_force=no","X-Spam_action":"no action","X-BeenThere":"qemu-devel@nongnu.org","X-Mailman-Version":"2.1.29","Precedence":"list","List-Id":"qemu development ","List-Unsubscribe":",\n ","List-Archive":"","List-Post":"","List-Help":"","List-Subscribe":",\n ","Errors-To":"qemu-devel-bounces+incoming=patchwork.ozlabs.org@nongnu.org","Sender":"qemu-devel-bounces+incoming=patchwork.ozlabs.org@nongnu.org"},"content":"From: Jamin Lin \n\nReplace legacy DPRINTF() debug logging in the EHCI host controller\nimplementation with QEMU trace events.\n\nThe EHCI_DEBUG macro and associated DPRINTF() definitions are\nremoved as they are no longer needed.\n\nTrace events are added for:\n- packet submission and completion\n- queue head execution state\n- periodic schedule advancement\n- ITD error conditions\n- port state handling\n- skipped microframes\n\nNo functional change.\n\nSigned-off-by: Jamin Lin \nReviewed-by: Philippe Mathieu-Daudé \nMessage-ID: <20260424080508.53992-7-jamin_lin@aspeedtech.com>\nSigned-off-by: Philippe Mathieu-Daudé \n---\n hw/usb/hcd-ehci.h | 10 ---------\n hw/usb/hcd-ehci.c | 49 +++++++++++++++++++--------------------------\n hw/usb/trace-events | 9 +++++++++\n 3 files changed, 30 insertions(+), 38 deletions(-)","diff":"diff --git a/hw/usb/hcd-ehci.h b/hw/usb/hcd-ehci.h\nindex 736407fd521..4234591cb41 100644\n--- a/hw/usb/hcd-ehci.h\n+++ b/hw/usb/hcd-ehci.h\n@@ -24,16 +24,6 @@\n #include \"hw/pci/pci_device.h\"\n #include \"hw/core/sysbus.h\"\n \n-#ifndef EHCI_DEBUG\n-#define EHCI_DEBUG 0\n-#endif\n-\n-#if EHCI_DEBUG\n-#define DPRINTF printf\n-#else\n-#define DPRINTF(...)\n-#endif\n-\n #define MMIO_SIZE 0x1000\n #define CAPA_SIZE 0x10\n \ndiff --git a/hw/usb/hcd-ehci.c b/hw/usb/hcd-ehci.c\nindex 8acaedeaa90..28a60e4c1a7 100644\n--- a/hw/usb/hcd-ehci.c\n+++ b/hw/usb/hcd-ehci.c\n@@ -839,7 +839,7 @@ static USBDevice *ehci_find_device(EHCIState *ehci, uint8_t addr)\n for (i = 0; i < EHCI_PORTS; i++) {\n port = &ehci->ports[i];\n if (!(ehci->portsc[i] & PORTSC_PED)) {\n- DPRINTF(\"Port %d not enabled\\n\", i);\n+ trace_usb_ehci_port_disable(i);\n continue;\n }\n dev = usb_find_device(port, addr);\n@@ -1281,10 +1281,8 @@ static void ehci_execute_complete(EHCIQueue *q)\n assert(p->async == EHCI_ASYNC_INITIALIZED ||\n p->async == EHCI_ASYNC_FINISHED);\n \n- DPRINTF(\"execute_complete: qhaddr 0x%x, next 0x%x, qtdaddr 0x%x, \"\n- \"status %d, actual_length %d\\n\",\n- q->qhaddr, q->qh.next, q->qtdaddr,\n- p->packet.status, p->packet.actual_length);\n+ trace_usb_ehci_execute_complete(q->qhaddr, q->qh.next, q->qtdaddr,\n+ p->packet.status, p->packet.actual_length);\n \n switch (p->packet.status) {\n case USB_RET_SUCCESS:\n@@ -1327,7 +1325,7 @@ static void ehci_execute_complete(EHCIQueue *q)\n } else {\n tbytes = 0;\n }\n- DPRINTF(\"updating tbytes to %d\\n\", tbytes);\n+ trace_usb_ehci_qh_tbytes(tbytes);\n set_field(&q->qh.token, tbytes, QTD_TOKEN_TBYTES);\n \n ehci_finish_transfer(q, p->packet.actual_length);\n@@ -1392,10 +1390,9 @@ static int ehci_execute(EHCIPacket *p, const char *action)\n \n trace_usb_ehci_packet_action(p->queue, p, action);\n usb_handle_packet(p->queue->dev, &p->packet);\n- DPRINTF(\"submit: qh 0x%x next 0x%x qtd 0x%x pid 0x%x len %zd endp 0x%x \"\n- \"status %d actual_length %d\\n\", p->queue->qhaddr, p->qtd.next,\n- p->qtdaddr, p->pid, p->packet.iov.size, endp, p->packet.status,\n- p->packet.actual_length);\n+ trace_usb_ehci_packet_submit(p->queue->qhaddr, p->qtd.next, p->qtdaddr,\n+ p->pid, p->packet.iov.size, endp,\n+ p->packet.status, p->packet.actual_length);\n \n if (p->packet.actual_length > BUFF_SIZE) {\n qemu_log_mask(LOG_GUEST_ERROR,\n@@ -1472,7 +1469,8 @@ static int ehci_process_itd(EHCIState *ehci,\n usb_handle_packet(dev, &ehci->ipacket);\n usb_packet_unmap(&ehci->ipacket, &ehci->isgl);\n } else {\n- DPRINTF(\"ISOCH: attempt to address non-iso endpoint\\n\");\n+ trace_usb_ehci_log(\"ISOCH: \"\n+ \"attempt to address non-iso endpoint\");\n ehci->ipacket.status = USB_RET_NAK;\n ehci->ipacket.actual_length = 0;\n }\n@@ -1677,24 +1675,22 @@ static EHCIQueue *ehci_state_fetchqh(EHCIState *ehci, int async)\n if (ehci->usbsts & USBSTS_REC) {\n ehci_clear_usbsts(ehci, USBSTS_REC);\n } else {\n- DPRINTF(\"FETCHQH: QH 0x%08x. H-bit set, reclamation status reset\"\n- \" - done processing\\n\", q->qhaddr);\n+ trace_usb_ehci_fetchqh_reclaim_done(q->qhaddr);\n ehci_set_state(ehci, async, EST_ACTIVE);\n q = NULL;\n goto out;\n }\n }\n \n-#if EHCI_DEBUG\n- if (q->qhaddr != q->qh.next) {\n- DPRINTF(\"FETCHQH: QH 0x%08x (h %x halt %x active %x) next 0x%08x\\n\",\n- q->qhaddr,\n- q->qh.epchar & QH_EPCHAR_H,\n- q->qh.token & QTD_TOKEN_HALT,\n- q->qh.token & QTD_TOKEN_ACTIVE,\n- q->qh.next);\n+ if (trace_event_get_state_backends(TRACE_USB_EHCI_FETCHQH_DBG)) {\n+ if (q->qhaddr != q->qh.next) {\n+ trace_usb_ehci_fetchqh_dbg(q->qhaddr,\n+ q->qh.epchar & QH_EPCHAR_H,\n+ q->qh.token & QTD_TOKEN_HALT,\n+ q->qh.token & QTD_TOKEN_ACTIVE,\n+ q->qh.next);\n+ }\n }\n-#endif\n \n if (q->qh.token & QTD_TOKEN_HALT) {\n ehci_set_state(ehci, async, EST_HORIZONTALQH);\n@@ -2161,7 +2157,7 @@ static void ehci_advance_async_state(EHCIState *ehci)\n /* make sure guest has acknowledged the doorbell interrupt */\n /* TO-DO: is this really needed? */\n if (ehci->usbsts & USBSTS_IAA) {\n- DPRINTF(\"IAA status bit still set.\\n\");\n+ trace_usb_ehci_log(\"IAA status bit still set.\");\n break;\n }\n \n@@ -2226,9 +2222,7 @@ static void ehci_advance_periodic_state(EHCIState *ehci)\n if (get_dwords(ehci, list, &entry, 1) < 0) {\n break;\n }\n-\n- DPRINTF(\"PERIODIC state adv fr=%d. [%08X] -> %08X\\n\",\n- ehci->frindex / 8, list, entry);\n+ trace_usb_ehci_periodic_state_advance(ehci->frindex / 8, list, entry);\n ehci_set_fetch_addr(ehci, async, entry);\n ehci_set_state(ehci, async, EST_FETCHENTRY);\n ehci_advance_state(ehci, async);\n@@ -2294,8 +2288,7 @@ static void ehci_work_bh(void *opaque)\n ehci_update_frindex(ehci, skipped_uframes);\n ehci->last_run_ns += UFRAME_TIMER_NS * skipped_uframes;\n uframes -= skipped_uframes;\n- DPRINTF(\"WARNING - EHCI skipped %\"PRIu64\" uframes\\n\",\n- skipped_uframes);\n+ trace_usb_ehci_skipped_uframes(skipped_uframes);\n }\n \n for (i = 0; i < uframes; i++) {\ndiff --git a/hw/usb/trace-events b/hw/usb/trace-events\nindex dd04f14add1..0d4318dcf14 100644\n--- a/hw/usb/trace-events\n+++ b/hw/usb/trace-events\n@@ -89,6 +89,7 @@ usb_ehci_state(const char *schedule, const char *state) \"%s schedule %s\"\n usb_ehci_qh_ptrs(void *q, uint32_t addr, uint32_t nxt, uint32_t c_qtd, uint32_t n_qtd, uint32_t a_qtd) \"q %p - QH @ 0x%08x: next 0x%08x qtds 0x%08x,0x%08x,0x%08x\"\n usb_ehci_qh_fields(uint32_t addr, int rl, int mplen, int eps, int ep, int devaddr) \"QH @ 0x%08x - rl %d, mplen %d, eps %d, ep %d, dev %d\"\n usb_ehci_qh_bits(uint32_t addr, int c, int h, int dtc, int i) \"QH @ 0x%08x - c %d, h %d, dtc %d, i %d\"\n+usb_ehci_qh_tbytes(uint32_t tbytes) \"updating tbytes to %d\"\n usb_ehci_qtd_ptrs(void *q, uint32_t addr, uint32_t nxt, uint32_t altnext) \"q %p - QTD @ 0x%08x: next 0x%08x altnext 0x%08x\"\n usb_ehci_qtd_fields(uint32_t addr, int tbytes, int cpage, int cerr, int pid) \"QTD @ 0x%08x - tbytes %d, cpage %d, cerr %d, pid %d\"\n usb_ehci_qtd_bits(uint32_t addr, int ioc, int active, int halt, int babble, int xacterr) \"QTD @ 0x%08x - ioc %d, active %d, halt %d, babble %d, xacterr %d\"\n@@ -100,13 +101,21 @@ usb_ehci_port_reset(uint32_t port, int enable) \"reset port #%d - %d\"\n usb_ehci_port_suspend(uint32_t port) \"port #%d\"\n usb_ehci_port_wakeup(uint32_t port) \"port #%d\"\n usb_ehci_port_resume(uint32_t port) \"port #%d\"\n+usb_ehci_port_disable(uint32_t port) \"port #%d\"\n usb_ehci_queue_action(void *q, const char *action) \"q %p: %s\"\n usb_ehci_packet_action(void *q, void *p, const char *action) \"q %p p %p: %s\"\n+usb_ehci_packet_submit(uint32_t qhaddr, uint32_t next, uint32_t qtdaddr, int pid, size_t len, int endp, int status, int actual_length) \"qh=0x%x, next=0x%x, qtd=0x%x, pid=0x%x, len=%zd, endp=0x%x, status=%d, actual_length=%d\"\n usb_ehci_irq(uint32_t level, uint32_t frindex, uint32_t sts, uint32_t mask) \"level %d, frindex 0x%04x, sts 0x%x, mask 0x%x\"\n usb_ehci_guest_bug(const char *reason) \"%s\"\n usb_ehci_doorbell_ring(void) \"\"\n usb_ehci_doorbell_ack(void) \"\"\n usb_ehci_dma_error(void) \"\"\n+usb_ehci_execute_complete(uint32_t qhaddr, uint32_t next, uint32_t qtdaddr, int status, int actual_length) \"qhaddr=0x%x, next=0x%x, qtdaddr=0x%x, status=%d, actual_length=%d\"\n+usb_ehci_fetchqh_reclaim_done(uint32_t qhaddr) \"QH 0x%08x H-bit set, reclamation status reset - done processing\"\n+usb_ehci_fetchqh_dbg(uint32_t qhaddr, uint32_t h, uint32_t halt, uint32_t active, uint32_t next) \"QH 0x%08x (h 0x%x halt 0x%x active 0x%x) next 0x%08x\"\n+usb_ehci_periodic_state_advance(uint32_t frame, uint32_t list, uint32_t entry) \"frame=%d, list=0x%x, entry=0x%x\"\n+usb_ehci_skipped_uframes(uint64_t skipped_uframes) \"skipped %\" PRIu64 \" uframes\"\n+usb_ehci_log(const char *msg) \"%s\"\n \n # hcd-uhci.c\n usb_uhci_reset(void) \"=== RESET ===\"\n","prefixes":["PULL","v4","54/62"]}