DM USB: modify some logs to help debug

Mainly change the logs for transfer submission and completion,
which are very important parts in USB emulation code.

Change-Id: I4e04f1426e164ca3693e70946ed51380201e49ee
Signed-off-by: Xiaoguang Wu <xiaoguang.wu@intel.com>
Reviewed-by: Liang Yang <liang3.yang@intel.com>
Acked-by: Yu Wang <yu1.wang@intel.com>

Author: xiaoguangwu

devicemodel/hw/pci/xhci.c

@@ -497,27 +497,27 @@ pci_xhci_native_usb_dev_conn_cb(void *hci_data, void *dev_data)
 	ue->ue_info(ud, USB_INFO_PORT, &native_port, sizeof(native_port));
 	ue->ue_info(ud, USB_INFO_VID, &native_vid, sizeof(native_vid));
 	ue->ue_info(ud, USB_INFO_PID, &native_pid, sizeof(native_pid));
-	UPRINTF(LDBG, "%X:%X %d-%d connecting.\r\n",
+	UPRINTF(LDBG, "%04x:%04x %d-%d connecting.\r\n",
 			native_vid, native_pid, native_bus, native_port);
 
 	/* FIXME: will support usb3 in future */
 	if (xdev->native_assign_ports[native_bus] &&
 			usb_native_is_ss_port(native_bus)) {
-		UPRINTF(LDBG, "%X:%X %d-%d not support usb3 device, exit.\r\n",
-				native_vid, native_pid, native_bus,
-				native_port);
+		UPRINTF(LDBG, "%04x:%04x %d-%d be ignored due to superspeed"
+				" device hasn't support yet\r\n", native_vid,
+				native_pid, native_bus, native_port);
 		goto errout;
 	}
 
 	if (!xdev->native_assign_ports[native_bus] ||
 			!xdev->native_assign_ports[native_bus][native_port]) {
-		UPRINTF(LDBG, "%X:%X %d-%d doesn't belong to this vm, bye.\r\n",
-				native_vid, native_pid, native_bus,
+		UPRINTF(LDBG, "%04x:%04x %d-%d doesn't belong to this vm, bye."
+				"\r\n", native_vid, native_pid, native_bus,
 				native_port);
 		goto errout;
 	}
 
-	UPRINTF(LDBG, "%X:%X %d-%d belong to this vm.\r\n", native_vid,
+	UPRINTF(LDBG, "%04x:%04x %d-%d belong to this vm.\r\n", native_vid,
 			native_pid, native_bus, native_port);
 
 	if (ue->ue_usbver == 2)

devicemodel/hw/platform/usb_pmapper.c

@@ -27,6 +27,7 @@ usb_dev_comp_req(struct libusb_transfer *libusb_xfer)
 	struct usb_data_xfer_block *block;
 	int len, do_intr = 0, short_data = 0;
 	int i, idx, buf_idx, done;
+	int bstart, bcount;
 
 	assert(libusb_xfer);
 	assert(libusb_xfer->user_data);
@@ -37,9 +38,15 @@ usb_dev_comp_req(struct libusb_transfer *libusb_xfer)
 
 	assert(xfer);
 	assert(xfer->dev);
-	UPRINTF(LDBG, "xfer_comp: ep %d with %d bytes. status %d,%d\n",
-			req->xfer->epid, len, libusb_xfer->status,
-			xfer->ndata);
+
+	bstart = req->blk_start;
+	bcount = req->blk_count;
+	UPRINTF(LDBG, "%s: actual_length %d ep%d-transfer (%d-%d %d) request-%d"
+			" (%d-%d %d) status %d\r\n", __func__, len, xfer->epid,
+			xfer->head, (xfer->tail - 1) % USB_MAX_XFER_BLOCKS,
+			xfer->ndata, req->seq, bstart, (bstart + bcount - 1) %
+			USB_MAX_XFER_BLOCKS, req->buf_length,
+			libusb_xfer->status);
 
 	/* lock for protecting the transfer */
 	USB_DATA_XFER_LOCK(xfer);
@@ -511,11 +518,6 @@ usb_dev_data(void *pdata, struct usb_data_xfer *xfer, int dir, int epctx)
 	if (data_size <= 0)
 		goto done;
 
-	UPRINTF(LDBG, "%s: DIR=%s|EP=%x|*%s*, data %d %d-%d\n", __func__,
-			dir ? "IN" : "OUT", epid, type == USB_ENDPOINT_BULK ?
-			"BULK" : "INT", data_size,
-			blk_start, blk_start + blk_count - 1);
-
 	req = usb_dev_alloc_req(udev, xfer, dir, data_size);
 	if (!req) {
 		xfer->status = USB_ERR_IOERROR;
@@ -691,10 +693,10 @@ usb_dev_init(void *pdata, char *opt)
 	port  = libusb_get_port_number(ldev);
 	bus   = libusb_get_bus_number(ldev);
 	libusb_get_device_descriptor(ldev, &desc);
-	UPRINTF(LINF, "Found USB device: %d-%d\r\nPID(0x%X), VID(0x%X) "
-			"CLASS(0x%X) SUBCLASS(0x%x) BCD(0x%x)\r\n", bus, port,
-			desc.idProduct, desc.idVendor,
-			desc.bDeviceClass, desc.bDeviceSubClass, desc.bcdUSB);
+	UPRINTF(LINF, "Found USB device: %d-%d\r\nPID(0x%X), VID(0x%X) CLASS"
+			"(0x%X) SUBCLASS(0x%X) BCD(0x%X) SPEED(%d)\r\n", bus,
+			port, desc.idProduct, desc.idVendor, desc.bDeviceClass,
+			desc.bDeviceSubClass, desc.bcdUSB, speed);
 
 	/* allocate and populate udev */
 	udev = calloc(1, sizeof(struct usb_dev));