From: Alexey Kardashevskiy <aik@ozlabs.ru>
To: qemu-devel@nongnu.org
Cc: Gerd Hoffmann <kraxel@redhat.com>
Subject: Re: [Qemu-devel] [PATCH] ohci: Convert fprint/DPRINTF/print to traces
Date: Fri, 19 Sep 2014 13:57:29 +1000 [thread overview]
Message-ID: <541BA9A9.80300@ozlabs.ru> (raw)
In-Reply-To: <1410512126-1580-1-git-send-email-aik@ozlabs.ru>
On 09/12/2014 06:55 PM, Alexey Kardashevskiy wrote:
> This converts many kinds of debug prints to traces.
>
> This implements packets logging to avoid unnecessary calculations if
> usb_ohci_td_pkt_short/usb_ohci_td_pkt_long is not enabled.
>
> This makes OHCI errors (such as "DMA error") invisible by default.
>
> Signed-off-by: Alexey Kardashevskiy <aik@ozlabs.ru>
> ---
>
>
> First I wanted to hide "DMA error" and "OHCI die" but then decided do to
> some housecleaning + community work :)
>
> I could have chosen wrong names for some traces, please comment. Thanks!
Ping.
Too much? Too bad? :)
Thanks!
>
> ---
> hw/usb/hcd-ohci.c | 214 +++++++++++++++++++++++-------------------------------
> trace-events | 56 ++++++++++++++
> 2 files changed, 148 insertions(+), 122 deletions(-)
>
> diff --git a/hw/usb/hcd-ohci.c b/hw/usb/hcd-ohci.c
> index 83bec34..4a4dd02 100644
> --- a/hw/usb/hcd-ohci.c
> +++ b/hw/usb/hcd-ohci.c
> @@ -31,20 +31,11 @@
> #include "hw/pci/pci.h"
> #include "hw/sysbus.h"
> #include "hw/qdev-dma.h"
> +#include "trace.h"
>
> -//#define DEBUG_OHCI
> -/* Dump packet contents. */
> -//#define DEBUG_PACKET
> -//#define DEBUG_ISOCH
> /* This causes frames to occur 1000x slower */
> //#define OHCI_TIME_WARP 1
>
> -#ifdef DEBUG_OHCI
> -#define DPRINTF printf
> -#else
> -#define DPRINTF(...)
> -#endif
> -
> /* Number of Downstream Ports on the root hub. */
>
> #define OHCI_MAX_PORTS 15
> @@ -350,7 +341,7 @@ static void ohci_attach(USBPort *port1)
> ohci_set_interrupt(s, OHCI_INTR_RD);
> }
>
> - DPRINTF("usb-ohci: Attached port %d\n", port1->index);
> + trace_usb_ohci_port_attach(port1->index);
>
> if (old_state != port->ctrl) {
> ohci_set_interrupt(s, OHCI_INTR_RHSC);
> @@ -375,7 +366,7 @@ static void ohci_detach(USBPort *port1)
> port->ctrl &= ~OHCI_PORT_PES;
> port->ctrl |= OHCI_PORT_PESC;
> }
> - DPRINTF("usb-ohci: Detached port %d\n", port1->index);
> + trace_usb_ohci_port_detach(port1->index);
>
> if (old_state != port->ctrl) {
> ohci_set_interrupt(s, OHCI_INTR_RHSC);
> @@ -388,14 +379,14 @@ static void ohci_wakeup(USBPort *port1)
> OHCIPort *port = &s->rhport[port1->index];
> uint32_t intr = 0;
> if (port->ctrl & OHCI_PORT_PSS) {
> - DPRINTF("usb-ohci: port %d: wakeup\n", port1->index);
> + trace_usb_ohci_port_wakeup(port1->index);
> port->ctrl |= OHCI_PORT_PSSC;
> port->ctrl &= ~OHCI_PORT_PSS;
> intr = OHCI_INTR_RHSC;
> }
> /* Note that the controller can be suspended even if this port is not */
> if ((s->ctl & OHCI_CTL_HCFS) == OHCI_USB_SUSPEND) {
> - DPRINTF("usb-ohci: remote-wakeup: SUSPEND->RESUME\n");
> + trace_usb_ohci_remote_wakeup(s->name);
> /* This is the one state transition the controller can do by itself */
> s->ctl &= ~OHCI_CTL_HCFS;
> s->ctl |= OHCI_USB_RESUME;
> @@ -497,7 +488,7 @@ static void ohci_reset(void *opaque)
> ohci->async_td = 0;
> }
> ohci_stop_endpoints(ohci);
> - DPRINTF("usb-ohci: Reset %s\n", ohci->name);
> + trace_usb_ohci_reset(ohci->name);
> }
>
> /* Get an array of dwords from main memory */
> @@ -690,9 +681,8 @@ static void ohci_process_lists(OHCIState *ohci, int completion);
> static void ohci_async_complete_packet(USBPort *port, USBPacket *packet)
> {
> OHCIState *ohci = container_of(packet, OHCIState, usb_packet);
> -#ifdef DEBUG_PACKET
> - DPRINTF("Async packet complete\n");
> -#endif
> +
> + trace_usb_ohci_async_complete();
> ohci->async_complete = true;
> ohci_process_lists(ohci, 1);
> }
> @@ -704,9 +694,7 @@ static int ohci_service_iso_td(OHCIState *ohci, struct ohci_ed *ed,
> {
> int dir;
> size_t len = 0;
> -#ifdef DEBUG_ISOCH
> const char *str = NULL;
> -#endif
> int pid;
> int ret;
> int i;
> @@ -723,7 +711,7 @@ static int ohci_service_iso_td(OHCIState *ohci, struct ohci_ed *ed,
> addr = ed->head & OHCI_DPTR_MASK;
>
> if (ohci_read_iso_td(ohci, addr, &iso_td)) {
> - printf("usb-ohci: ISO_TD read error at %x\n", addr);
> + trace_usb_ohci_iso_td_read_failed(addr);
> ohci_die(ohci);
> return 0;
> }
> @@ -732,14 +720,7 @@ static int ohci_service_iso_td(OHCIState *ohci, struct ohci_ed *ed,
> frame_count = OHCI_BM(iso_td.flags, TD_FC);
> relative_frame_number = USUB(ohci->frame_number, starting_frame);
>
> -#ifdef DEBUG_ISOCH
> - printf("--- ISO_TD ED head 0x%.8x tailp 0x%.8x\n"
> - "0x%.8x 0x%.8x 0x%.8x 0x%.8x\n"
> - "0x%.8x 0x%.8x 0x%.8x 0x%.8x\n"
> - "0x%.8x 0x%.8x 0x%.8x 0x%.8x\n"
> - "frame_number 0x%.8x starting_frame 0x%.8x\n"
> - "frame_count 0x%.8x relative %d\n"
> - "di 0x%.8x cc 0x%.8x\n",
> + trace_usb_ohci_iso_td_head(
> ed->head & OHCI_DPTR_MASK, ed->tail & OHCI_DPTR_MASK,
> iso_td.flags, iso_td.bp, iso_td.next, iso_td.be,
> iso_td.offset[0], iso_td.offset[1], iso_td.offset[2], iso_td.offset[3],
> @@ -747,16 +728,15 @@ static int ohci_service_iso_td(OHCIState *ohci, struct ohci_ed *ed,
> ohci->frame_number, starting_frame,
> frame_count, relative_frame_number,
> OHCI_BM(iso_td.flags, TD_DI), OHCI_BM(iso_td.flags, TD_CC));
> -#endif
>
> if (relative_frame_number < 0) {
> - DPRINTF("usb-ohci: ISO_TD R=%d < 0\n", relative_frame_number);
> + trace_usb_ohci_iso_td_relative_frame_number_neg(relative_frame_number);
> return 1;
> } else if (relative_frame_number > frame_count) {
> /* ISO TD expired - retire the TD to the Done Queue and continue with
> the next ISO TD of the same ED */
> - DPRINTF("usb-ohci: ISO_TD R=%d > FC=%d\n", relative_frame_number,
> - frame_count);
> + trace_usb_ohci_iso_td_relative_frame_number_big(relative_frame_number,
> + frame_count);
> OHCI_SET_BM(iso_td.flags, TD_CC, OHCI_CC_DATAOVERRUN);
> ed->head &= ~OHCI_DPTR_MASK;
> ed->head |= (iso_td.next & OHCI_DPTR_MASK);
> @@ -775,30 +755,24 @@ static int ohci_service_iso_td(OHCIState *ohci, struct ohci_ed *ed,
> dir = OHCI_BM(ed->flags, ED_D);
> switch (dir) {
> case OHCI_TD_DIR_IN:
> -#ifdef DEBUG_ISOCH
> str = "in";
> -#endif
> pid = USB_TOKEN_IN;
> break;
> case OHCI_TD_DIR_OUT:
> -#ifdef DEBUG_ISOCH
> str = "out";
> -#endif
> pid = USB_TOKEN_OUT;
> break;
> case OHCI_TD_DIR_SETUP:
> -#ifdef DEBUG_ISOCH
> str = "setup";
> -#endif
> pid = USB_TOKEN_SETUP;
> break;
> default:
> - printf("usb-ohci: Bad direction %d\n", dir);
> + trace_usb_ohci_iso_td_bad_direction(dir);
> return 1;
> }
>
> if (!iso_td.bp || !iso_td.be) {
> - printf("usb-ohci: ISO_TD bp 0x%.8x be 0x%.8x\n", iso_td.bp, iso_td.be);
> + trace_usb_ohci_iso_td_bad_bp_be(iso_td.bp, iso_td.be);
> return 1;
> }
>
> @@ -808,14 +782,12 @@ static int ohci_service_iso_td(OHCIState *ohci, struct ohci_ed *ed,
> if (!(OHCI_BM(start_offset, TD_PSW_CC) & 0xe) ||
> ((relative_frame_number < frame_count) &&
> !(OHCI_BM(next_offset, TD_PSW_CC) & 0xe))) {
> - printf("usb-ohci: ISO_TD cc != not accessed 0x%.8x 0x%.8x\n",
> - start_offset, next_offset);
> + trace_usb_ohci_iso_td_bad_cc_not_accessed(start_offset, next_offset);
> return 1;
> }
>
> if ((relative_frame_number < frame_count) && (start_offset > next_offset)) {
> - printf("usb-ohci: ISO_TD start_offset=0x%.8x > next_offset=0x%.8x\n",
> - start_offset, next_offset);
> + trace_usb_ohci_iso_td_bad_cc_overrun(start_offset, next_offset);
> return 1;
> }
>
> @@ -875,10 +847,8 @@ static int ohci_service_iso_td(OHCIState *ohci, struct ohci_ed *ed,
> ret = ohci->usb_packet.status;
> }
>
> -#ifdef DEBUG_ISOCH
> - printf("so 0x%.8x eo 0x%.8x\nsa 0x%.8x ea 0x%.8x\ndir %s len %zu ret %d\n",
> - start_offset, end_offset, start_addr, end_addr, str, len, ret);
> -#endif
> + trace_usb_ohci_iso_td_so(start_offset, end_offset, start_addr, end_addr,
> + str, len, ret);
>
> /* Writeback */
> if (dir == OHCI_TD_DIR_IN && ret >= 0 && ret <= len) {
> @@ -898,13 +868,13 @@ static int ohci_service_iso_td(OHCIState *ohci, struct ohci_ed *ed,
> OHCI_SET_BM(iso_td.offset[relative_frame_number], TD_PSW_SIZE, 0);
> } else {
> if (ret > (ssize_t) len) {
> - printf("usb-ohci: DataOverrun %d > %zu\n", ret, len);
> + trace_usb_ohci_iso_td_data_overrun(ret, len);
> OHCI_SET_BM(iso_td.offset[relative_frame_number], TD_PSW_CC,
> OHCI_CC_DATAOVERRUN);
> OHCI_SET_BM(iso_td.offset[relative_frame_number], TD_PSW_SIZE,
> len);
> } else if (ret >= 0) {
> - printf("usb-ohci: DataUnderrun %d\n", ret);
> + trace_usb_ohci_iso_td_data_underrun(ret);
> OHCI_SET_BM(iso_td.offset[relative_frame_number], TD_PSW_CC,
> OHCI_CC_DATAUNDERRUN);
> } else {
> @@ -918,14 +888,14 @@ static int ohci_service_iso_td(OHCIState *ohci, struct ohci_ed *ed,
> break;
> case USB_RET_NAK:
> case USB_RET_STALL:
> - printf("usb-ohci: got NAK/STALL %d\n", ret);
> + trace_usb_ohci_iso_td_nak(ret);
> OHCI_SET_BM(iso_td.offset[relative_frame_number], TD_PSW_CC,
> OHCI_CC_STALL);
> OHCI_SET_BM(iso_td.offset[relative_frame_number], TD_PSW_SIZE,
> 0);
> break;
> default:
> - printf("usb-ohci: Bad device response %d\n", ret);
> + trace_usb_ohci_iso_td_bad_response(ret);
> OHCI_SET_BM(iso_td.offset[relative_frame_number], TD_PSW_CC,
> OHCI_CC_UNDEXPETEDPID);
> break;
> @@ -950,6 +920,37 @@ static int ohci_service_iso_td(OHCIState *ohci, struct ohci_ed *ed,
> return 1;
> }
>
> +static void ohci_td_pkt(const char *msg, const uint8_t *buf, size_t len)
> +{
> + bool print16 = !!trace_event_get_state(TRACE_USB_OHCI_TD_PKT_SHORT);
> + bool printall = !!trace_event_get_state(TRACE_USB_OHCI_TD_PKT_FULL);
> + const int width = 16;
> + int i;
> + char tmp[3 * width + 1];
> + char *p = tmp;
> +
> + if (!printall && !print16) {
> + return;
> + }
> +
> + for (i = 0; ; i++) {
> + if (i && (!(i % width) || (i == len))) {
> + if (!printall) {
> + trace_usb_ohci_td_pkt_short(msg, tmp);
> + break;
> + }
> + trace_usb_ohci_td_pkt_full(msg, tmp);
> + p = tmp;
> + *p = 0;
> + }
> + if (i == len) {
> + break;
> + }
> +
> + p += sprintf(p, " %.2x", buf[i]);
> + }
> +}
> +
> /* Service a transport descriptor.
> Returns nonzero to terminate processing of this endpoint. */
>
> @@ -957,9 +958,7 @@ static int ohci_service_td(OHCIState *ohci, struct ohci_ed *ed)
> {
> int dir;
> size_t len = 0, pktlen = 0;
> -#ifdef DEBUG_PACKET
> const char *str = NULL;
> -#endif
> int pid;
> int ret;
> int i;
> @@ -974,13 +973,11 @@ static int ohci_service_td(OHCIState *ohci, struct ohci_ed *ed)
> /* See if this TD has already been submitted to the device. */
> completion = (addr == ohci->async_td);
> if (completion && !ohci->async_complete) {
> -#ifdef DEBUG_PACKET
> - DPRINTF("Skipping async TD\n");
> -#endif
> + trace_usb_ohci_td_skip_async();
> return 1;
> }
> if (ohci_read_td(ohci, addr, &td)) {
> - fprintf(stderr, "usb-ohci: TD read error at %x\n", addr);
> + trace_usb_ohci_td_read_error(addr);
> ohci_die(ohci);
> return 0;
> }
> @@ -998,25 +995,19 @@ static int ohci_service_td(OHCIState *ohci, struct ohci_ed *ed)
>
> switch (dir) {
> case OHCI_TD_DIR_IN:
> -#ifdef DEBUG_PACKET
> str = "in";
> -#endif
> pid = USB_TOKEN_IN;
> break;
> case OHCI_TD_DIR_OUT:
> -#ifdef DEBUG_PACKET
> str = "out";
> -#endif
> pid = USB_TOKEN_OUT;
> break;
> case OHCI_TD_DIR_SETUP:
> -#ifdef DEBUG_PACKET
> str = "setup";
> -#endif
> pid = USB_TOKEN_SETUP;
> break;
> default:
> - fprintf(stderr, "usb-ohci: Bad direction\n");
> + trace_usb_ohci_td_bad_direction(dir);
> return 1;
> }
> if (td.cbp && td.be) {
> @@ -1043,19 +1034,10 @@ static int ohci_service_td(OHCIState *ohci, struct ohci_ed *ed)
> }
>
> flag_r = (td.flags & OHCI_TD_R) != 0;
> -#ifdef DEBUG_PACKET
> - DPRINTF(" TD @ 0x%.8x %" PRId64 " of %" PRId64
> - " bytes %s r=%d cbp=0x%.8x be=0x%.8x\n",
> - addr, (int64_t)pktlen, (int64_t)len, str, flag_r, td.cbp, td.be);
> + trace_usb_ohci_td_pkt_hdr(addr, (int64_t)pktlen, (int64_t)len, str,
> + flag_r, td.cbp, td.be);
> + ohci_td_pkt("OUT", ohci->usb_buf, pktlen);
>
> - if (pktlen > 0 && dir != OHCI_TD_DIR_IN) {
> - DPRINTF(" data:");
> - for (i = 0; i < pktlen; i++) {
> - printf(" %.2x", ohci->usb_buf[i]);
> - }
> - DPRINTF("\n");
> - }
> -#endif
> if (completion) {
> ohci->async_td = 0;
> ohci->async_complete = false;
> @@ -1066,9 +1048,7 @@ static int ohci_service_td(OHCIState *ohci, struct ohci_ed *ed)
> This should be sufficient as long as devices respond in a
> timely manner.
> */
> -#ifdef DEBUG_PACKET
> - DPRINTF("Too many pending packets\n");
> -#endif
> + trace_usb_ohci_td_too_many_pending();
> return 1;
> }
> dev = ohci_find_device(ohci, OHCI_BM(ed->flags, ED_FA));
> @@ -1077,9 +1057,8 @@ static int ohci_service_td(OHCIState *ohci, struct ohci_ed *ed)
> OHCI_BM(td.flags, TD_DI) == 0);
> usb_packet_addbuf(&ohci->usb_packet, ohci->usb_buf, pktlen);
> usb_handle_packet(dev, &ohci->usb_packet);
> -#ifdef DEBUG_PACKET
> - DPRINTF("status=%d\n", ohci->usb_packet.status);
> -#endif
> + trace_usb_ohci_td_packet_status(ohci->usb_packet.status);
> +
> if (ohci->usb_packet.status == USB_RET_ASYNC) {
> usb_device_flush_ep_queue(dev, ep);
> ohci->async_td = addr;
> @@ -1098,12 +1077,7 @@ static int ohci_service_td(OHCIState *ohci, struct ohci_ed *ed)
> DMA_DIRECTION_FROM_DEVICE)) {
> ohci_die(ohci);
> }
> -#ifdef DEBUG_PACKET
> - DPRINTF(" data:");
> - for (i = 0; i < ret; i++)
> - printf(" %.2x", ohci->usb_buf[i]);
> - DPRINTF("\n");
> -#endif
> + ohci_td_pkt("IN", ohci->usb_buf, pktlen);
> } else {
> ret = pktlen;
> }
> @@ -1137,28 +1111,28 @@ static int ohci_service_td(OHCIState *ohci, struct ohci_ed *ed)
> ed->head |= OHCI_ED_C;
> } else {
> if (ret >= 0) {
> - DPRINTF("usb-ohci: Underrun\n");
> + trace_usb_ohci_td_underrun();
> OHCI_SET_BM(td.flags, TD_CC, OHCI_CC_DATAUNDERRUN);
> } else {
> switch (ret) {
> case USB_RET_IOERROR:
> case USB_RET_NODEV:
> - DPRINTF("usb-ohci: got DEV ERROR\n");
> + trace_usb_ohci_td_dev_error();
> OHCI_SET_BM(td.flags, TD_CC, OHCI_CC_DEVICENOTRESPONDING);
> break;
> case USB_RET_NAK:
> - DPRINTF("usb-ohci: got NAK\n");
> + trace_usb_ohci_td_nak();
> return 1;
> case USB_RET_STALL:
> - DPRINTF("usb-ohci: got STALL\n");
> + trace_usb_ohci_td_stall();
> OHCI_SET_BM(td.flags, TD_CC, OHCI_CC_STALL);
> break;
> case USB_RET_BABBLE:
> - DPRINTF("usb-ohci: got BABBLE\n");
> + trace_usb_ohci_td_babble();
> OHCI_SET_BM(td.flags, TD_CC, OHCI_CC_DATAOVERRUN);
> break;
> default:
> - fprintf(stderr, "usb-ohci: Bad device response %d\n", ret);
> + trace_usb_ohci_td_bad_device_response(ret);
> OHCI_SET_BM(td.flags, TD_CC, OHCI_CC_UNDEXPETEDPID);
> OHCI_SET_BM(td.flags, TD_EC, 3);
> break;
> @@ -1198,7 +1172,7 @@ static int ohci_service_ed_list(OHCIState *ohci, uint32_t head, int completion)
>
> for (cur = head; cur; cur = next_ed) {
> if (ohci_read_ed(ohci, cur, &ed)) {
> - fprintf(stderr, "usb-ohci: ED read error at %x\n", cur);
> + trace_usb_ohci_ed_read_error(cur);
> ohci_die(ohci);
> return 0;
> }
> @@ -1219,16 +1193,14 @@ static int ohci_service_ed_list(OHCIState *ohci, uint32_t head, int completion)
> }
>
> while ((ed.head & OHCI_DPTR_MASK) != ed.tail) {
> -#ifdef DEBUG_PACKET
> - DPRINTF("ED @ 0x%.8x fa=%u en=%u d=%u s=%u k=%u f=%u mps=%u "
> - "h=%u c=%u\n head=0x%.8x tailp=0x%.8x next=0x%.8x\n", cur,
> + trace_usb_ohci_ed_pkt(cur,
> OHCI_BM(ed.flags, ED_FA), OHCI_BM(ed.flags, ED_EN),
> OHCI_BM(ed.flags, ED_D), (ed.flags & OHCI_ED_S)!= 0,
> (ed.flags & OHCI_ED_K) != 0, (ed.flags & OHCI_ED_F) != 0,
> OHCI_BM(ed.flags, ED_MPS), (ed.head & OHCI_ED_H) != 0,
> (ed.head & OHCI_ED_C) != 0, ed.head & OHCI_DPTR_MASK,
> ed.tail & OHCI_DPTR_MASK, ed.next & OHCI_DPTR_MASK);
> -#endif
> +
> active = 1;
>
> if ((ed.flags & OHCI_ED_F) == 0) {
> @@ -1263,8 +1235,7 @@ static void ohci_process_lists(OHCIState *ohci, int completion)
> {
> if ((ohci->ctl & OHCI_CTL_CLE) && (ohci->status & OHCI_STATUS_CLF)) {
> if (ohci->ctrl_cur && ohci->ctrl_cur != ohci->ctrl_head) {
> - DPRINTF("usb-ohci: head %x, cur %x\n",
> - ohci->ctrl_head, ohci->ctrl_cur);
> + trace_usb_ohci_process_lists(ohci->ctrl_head, ohci->ctrl_cur);
> }
> if (!ohci_service_ed_list(ohci, ohci->ctrl_head, completion)) {
> ohci->ctrl_cur = 0;
> @@ -1287,7 +1258,7 @@ static void ohci_frame_boundary(void *opaque)
> struct ohci_hcca hcca;
>
> if (ohci_read_hcca(ohci, ohci->hcca, &hcca)) {
> - fprintf(stderr, "usb-ohci: HCCA read error at %x\n", ohci->hcca);
> + trace_usb_ohci_hcca_read_error(ohci->hcca);
> ohci_die(ohci);
> return;
> }
> @@ -1356,12 +1327,12 @@ static int ohci_bus_start(OHCIState *ohci)
> ohci);
>
> if (ohci->eof_timer == NULL) {
> - fprintf(stderr, "usb-ohci: %s: timer_new_ns failed\n", ohci->name);
> + trace_usb_ohci_bus_eof_timer_failed(ohci->name);
> ohci_die(ohci);
> return 0;
> }
>
> - DPRINTF("usb-ohci: %s: USB Operational\n", ohci->name);
> + trace_usb_ohci_start(ohci->name);
>
> ohci_sof(ohci);
>
> @@ -1371,6 +1342,7 @@ static int ohci_bus_start(OHCIState *ohci)
> /* Stop sending SOF tokens on the bus */
> static void ohci_bus_stop(OHCIState *ohci)
> {
> + trace_usb_ohci_stop(ohci->name);
> if (ohci->eof_timer) {
> timer_del(ohci->eof_timer);
> timer_free(ohci->eof_timer);
> @@ -1416,8 +1388,7 @@ static void ohci_set_frame_interval(OHCIState *ohci, uint16_t val)
> val &= OHCI_FMI_FI;
>
> if (val != ohci->fi) {
> - DPRINTF("usb-ohci: %s: FrameInterval = 0x%x (%u)\n",
> - ohci->name, ohci->fi, ohci->fi);
> + trace_usb_ohci_set_frame_interval(ohci->name, ohci->fi, ohci->fi);
> }
>
> ohci->fi = val;
> @@ -1449,20 +1420,19 @@ static void ohci_set_ctl(OHCIState *ohci, uint32_t val)
> if (old_state == new_state)
> return;
>
> + trace_usb_ohci_set_ctl(ohci->name, new_state);
> switch (new_state) {
> case OHCI_USB_OPERATIONAL:
> ohci_bus_start(ohci);
> break;
> case OHCI_USB_SUSPEND:
> ohci_bus_stop(ohci);
> - DPRINTF("usb-ohci: %s: USB Suspended\n", ohci->name);
> break;
> case OHCI_USB_RESUME:
> - DPRINTF("usb-ohci: %s: USB Resume\n", ohci->name);
> + trace_usb_ohci_resume(ohci->name);
> break;
> case OHCI_USB_RESET:
> ohci_reset(ohci);
> - DPRINTF("usb-ohci: %s: USB Reset\n", ohci->name);
> break;
> }
> }
> @@ -1507,7 +1477,7 @@ static void ohci_set_hub_status(OHCIState *ohci, uint32_t val)
>
> for (i = 0; i < ohci->num_ports; i++)
> ohci_port_power(ohci, i, 0);
> - DPRINTF("usb-ohci: powered down all ports\n");
> + trace_usb_ohci_hub_power_down();
> }
>
> if (val & OHCI_RHS_LPSC) {
> @@ -1515,7 +1485,7 @@ static void ohci_set_hub_status(OHCIState *ohci, uint32_t val)
>
> for (i = 0; i < ohci->num_ports; i++)
> ohci_port_power(ohci, i, 1);
> - DPRINTF("usb-ohci: powered up all ports\n");
> + trace_usb_ohci_hub_power_up();
> }
>
> if (val & OHCI_RHS_DRWE)
> @@ -1547,11 +1517,11 @@ static void ohci_port_set_status(OHCIState *ohci, int portnum, uint32_t val)
> ohci_port_set_if_connected(ohci, portnum, val & OHCI_PORT_PES);
>
> if (ohci_port_set_if_connected(ohci, portnum, val & OHCI_PORT_PSS)) {
> - DPRINTF("usb-ohci: port %d: SUSPEND\n", portnum);
> + trace_usb_ohci_port_suspend(portnum);
> }
>
> if (ohci_port_set_if_connected(ohci, portnum, val & OHCI_PORT_PRS)) {
> - DPRINTF("usb-ohci: port %d: RESET\n", portnum);
> + trace_usb_ohci_port_reset(portnum);
> usb_device_reset(port->port.dev);
> port->ctrl &= ~OHCI_PORT_PRS;
> /* ??? Should this also set OHCI_PORT_PESC. */
> @@ -1579,7 +1549,7 @@ static uint64_t ohci_mem_read(void *opaque,
>
> /* Only aligned reads are allowed on OHCI */
> if (addr & 3) {
> - fprintf(stderr, "usb-ohci: Mis-aligned read\n");
> + trace_usb_ohci_mem_read_unaligned(addr);
> return 0xffffffff;
> } else if (addr >= 0x54 && addr < 0x54 + ohci->num_ports * 4) {
> /* HcRhPortStatus */
> @@ -1685,7 +1655,7 @@ static uint64_t ohci_mem_read(void *opaque,
> break;
>
> default:
> - fprintf(stderr, "ohci_read: Bad offset %x\n", (int)addr);
> + trace_usb_ohci_mem_read_bad_offset(addr);
> retval = 0xffffffff;
> }
> }
> @@ -1702,7 +1672,7 @@ static void ohci_mem_write(void *opaque,
>
> /* Only aligned reads are allowed on OHCI */
> if (addr & 3) {
> - fprintf(stderr, "usb-ohci: Mis-aligned write\n");
> + trace_usb_ohci_mem_write_unaligned(addr);
> return;
> }
>
> @@ -1816,7 +1786,7 @@ static void ohci_mem_write(void *opaque,
> break;
>
> default:
> - fprintf(stderr, "ohci_write: Bad offset %x\n", (int)addr);
> + trace_usb_ohci_mem_write_bad_offset(addr);
> break;
> }
> }
> @@ -1869,8 +1839,7 @@ static int usb_ohci_init(OHCIState *ohci, DeviceState *dev,
> usb_bit_time = 1;
> }
> #endif
> - DPRINTF("usb-ohci: usb_bit_time=%" PRId64 " usb_frame_time=%" PRId64 "\n",
> - usb_frame_time, usb_bit_time);
> + trace_usb_ohci_init_time(usb_frame_time, usb_bit_time);
> }
>
> ohci->num_ports = num_ports;
> @@ -1928,7 +1897,7 @@ static void ohci_die(OHCIState *ohci)
> {
> OHCIPCIState *dev = container_of(ohci, OHCIPCIState, state);
>
> - fprintf(stderr, "%s: DMA error\n", __func__);
> + trace_usb_ohci_die();
>
> ohci_set_interrupt(ohci, OHCI_INTR_UE);
> ohci_bus_stop(ohci);
> @@ -1959,6 +1928,7 @@ static void usb_ohci_exit(PCIDevice *dev)
> OHCIPCIState *ohci = PCI_OHCI(dev);
> OHCIState *s = &ohci->state;
>
> + trace_usb_ohci_exit(s->name);
> ohci_bus_stop(s);
>
> if (s->async_td) {
> diff --git a/trace-events b/trace-events
> index 03ac5d2..a747ab1 100644
> --- a/trace-events
> +++ b/trace-events
> @@ -295,6 +295,62 @@ usb_port_attach(int bus, const char *port, const char *devspeed, const char *por
> usb_port_detach(int bus, const char *port) "bus %d, port %s"
> usb_port_release(int bus, const char *port) "bus %d, port %s"
>
> +# hw/usb/hcd-ohci.c
> +usb_ohci_iso_td_read_failed(uint32_t addr) "ISO_TD read error at %x"
> +usb_ohci_iso_td_head(uint32_t head, uint32_t tail, uint32_t flags, uint32_t bp, uint32_t next, uint32_t be, uint32_t o0, uint32_t o1, uint32_t o2, uint32_t o3, uint32_t o4, uint32_t o5, uint32_t o6, uint32_t o7, uint32_t framenum, uint32_t startframe, uint32_t framecount, int rel_frame_num, uint32_t bm_di, uint32_t td_cc) "ISO_TD ED head 0x%.8x tailp 0x%.8x\n0x%.8x 0x%.8x 0x%.8x 0x%.8x\n0x%.8x 0x%.8x 0x%.8x 0x%.8x\n0x%.8x 0x%.8x 0x%.8x 0x%.8x\nframe_number 0x%.8x starting_frame 0x%.8x\nframe_count 0x%.8x relative %d\ndi 0x%.8x cc 0x%.8x"
> +usb_ohci_iso_td_relative_frame_number_neg(int rel) "ISO_TD R=%d < 0"
> +usb_ohci_iso_td_relative_frame_number_big(int rel, int count) "ISO_TD R=%d > FC=%d"
> +usb_ohci_iso_td_bad_direction(int dir) "Bad direction %d"
> +usb_ohci_iso_td_bad_bp_be(uint32_t bp, uint32_t be) "ISO_TD bp 0x%.8x be 0x%.8x"
> +usb_ohci_iso_td_bad_cc_not_accessed(uint32_t start, uint32_t next) "ISO_TD cc != not accessed 0x%.8x 0x%.8x"
> +usb_ohci_iso_td_bad_cc_overrun(uint32_t start, uint32_t next) "ISO_TD start_offset=0x%.8x > next_offset=0x%.8x"
> +usb_ohci_iso_td_so(uint32_t so, uint32_t eo, uint32_t s, uint32_t e, const char *str, ssize_t len, int ret) "0x%.8x eo 0x%.8x\nsa 0x%.8x ea 0x%.8x\ndir %s len %zu ret %d"
> +usb_ohci_iso_td_data_overrun(int ret, ssize_t len) "DataOverrun %d > %zu"
> +usb_ohci_iso_td_data_underrun(int ret) "DataUnderrun %d"
> +usb_ohci_iso_td_nak(int ret) "got NAK/STALL %d"
> +usb_ohci_iso_td_bad_response(int ret) "Bad device response %d"
> +usb_ohci_port_attach(int index) "port #%d"
> +usb_ohci_port_detach(int index) "port #%d"
> +usb_ohci_port_wakeup(int index) "port #%d"
> +usb_ohci_port_suspend(int index) "port #%d"
> +usb_ohci_port_reset(int index) "port #%d"
> +usb_ohci_remote_wakeup(const char *s) "%s: SUSPEND->RESUME"
> +usb_ohci_reset(const char *s) "%s"
> +usb_ohci_start(const char *s) "%s: USB Operational"
> +usb_ohci_resume(const char *s) "%s: USB Resume"
> +usb_ohci_stop(const char *s) "%s: USB Suspended"
> +usb_ohci_exit(const char *s) "%s"
> +usb_ohci_set_ctl(const char *s, uint32_t new_state) "%s: new state 0x%x"
> +usb_ohci_td_underrun(void) ""
> +usb_ohci_td_dev_error(void) ""
> +usb_ohci_td_nak(void) ""
> +usb_ohci_td_stall(void) ""
> +usb_ohci_td_babble(void) ""
> +usb_ohci_td_bad_device_response(int rc) "%d"
> +usb_ohci_td_read_error(uint32_t addr) "TD read error at %x"
> +usb_ohci_td_bad_direction(int dir) "Bad direction %d"
> +usb_ohci_td_skip_async(void) ""
> +usb_ohci_td_pkt_hdr(uint32_t addr, int64_t pktlen, int64_t len, const char *s, int flag_r, uint32_t cbp, uint32_t be) " TD @ 0x%.8x %" PRId64 " of %" PRId64 " bytes %s r=%d cbp=0x%.8x be=0x%.8x"
> +usb_ohci_td_pkt_short(const char *dir, const char *buf) "%s data: %s"
> +usb_ohci_td_pkt_full(const char *dir, const char *buf) "%s data: %s"
> +usb_ohci_td_too_many_pending(void) ""
> +usb_ohci_td_packet_status(int status) "status=%d"
> +usb_ohci_ed_read_error(uint32_t addr) "ED read error at %x"
> +usb_ohci_ed_pkt(uint32_t cur, uint32_t fa, uint32_t en, uint32_t d, int s, int k, int f, uint32_t mps, int h, int c, uint32_t head, uint32_t tail, uint32_t next) "ED @ 0x%.8x fa=%u en=%u d=%u s=%u k=%u f=%u mps=%u h=%u c=%u\n head=0x%.8x tailp=0x%.8x next=0x%.8x"
> +usb_ohci_hcca_read_error(uint32_t addr) "HCCA read error at %x"
> +usb_ohci_mem_read_unaligned(uint32_t addr) "at %x"
> +usb_ohci_mem_read_bad_offset(uint32_t addr) "%x"
> +usb_ohci_mem_write_unaligned(uint32_t addr) "at %x"
> +usb_ohci_mem_write_bad_offset(uint32_t addr) "%x"
> +usb_ohci_process_lists(uint32_t head, uint32_t cur) "head %x, cur %x"
> +usb_ohci_bus_eof_timer_failed(const char *name) "%s: timer_new_ns failed"
> +usb_ohci_set_frame_interval(const char *name, uint16_t fi_x, uint16_t fi_u) "%s: FrameInterval = 0x%x (%u)"
> +usb_ohci_hub_power_up(void) "powered up all ports"
> +usb_ohci_hub_power_down(void) "powered down all ports"
> +usb_ohci_init_time(int64_t frametime, int64_t bittime) "usb_bit_time=%" PRId64 " usb_frame_time=%" PRId64
> +usb_ohci_die(void) ""
> +usb_ohci_async_complete(void) ""
> +
> # hw/usb/hcd-ehci.c
> usb_ehci_reset(void) "=== RESET ==="
> usb_ehci_unrealize(void) "=== UNREALIZE ==="
>
--
Alexey
next prev parent reply other threads:[~2014-09-19 3:57 UTC|newest]
Thread overview: 3+ messages / expand[flat|nested] mbox.gz Atom feed top
2014-09-12 8:55 [Qemu-devel] [PATCH] ohci: Convert fprint/DPRINTF/print to traces Alexey Kardashevskiy
2014-09-19 3:57 ` Alexey Kardashevskiy [this message]
2014-09-19 6:16 ` Gerd Hoffmann
Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
Avoid top-posting and favor interleaved quoting:
https://en.wikipedia.org/wiki/Posting_style#Interleaved_style
* Reply using the --to, --cc, and --in-reply-to
switches of git-send-email(1):
git send-email \
--in-reply-to=541BA9A9.80300@ozlabs.ru \
--to=aik@ozlabs.ru \
--cc=kraxel@redhat.com \
--cc=qemu-devel@nongnu.org \
/path/to/YOUR_REPLY
https://kernel.org/pub/software/scm/git/docs/git-send-email.html
* If your mail client supports setting the In-Reply-To header
via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line
before the message body.
This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.