libpayload: Reduce verbosity in USB stack

The USB stack is pretty noisy. Reduce the output to a sane level.

Change-Id: I250949e5cf74a8c6d43822b2e7487143b2ae1c65
Signed-off-by: Mathias Krause <mathias.krause@secunet.com>
Reviewed-on: http://review.coreboot.org/393
Tested-by: build bot (Jenkins)
Reviewed-by: Stefan Reinauer <stefan.reinauer@coreboot.org>

8 files changed, 83 insertions, 84 deletions

diff --git a/payloads/libpayload/drivers/usb/ehci.c b/payloads/libpayload/drivers/usb/ehci.c
index d97912140a..f258e075e3 100644
--- a/payloads/libpayload/drivers/usb/ehci.c
+++ b/payloads/libpayload/drivers/usb/ehci.c
@@ -34,9 +34,9 @@
 static void dump_td(u32 addr)
 {
 	qtd_t *td = phys_to_virt(addr);
-	printf("td at phys(%x): active: %x, halted: %x, data_buf_err: %x\n    babble: %x, xact_err: %x, missed_mframe: %x\n    splitxstate: %x, perr: %x\n\n",
+	debug("td at phys(%x): active: %x, halted: %x, data_buf_err: %x\n    babble: %x, xact_err: %x, missed_mframe: %x\n    splitxstate: %x, perr: %x\n\n",
 		addr, td->active, td->halted, td->data_buf_err, td->babble, td->xact_err, td->missed_mframe, td->splitxstate, td->perr);
-	printf("-   cerr: %x, total_len: %x\n\n", td->cerr, td->total_len);
+	debug("-   cerr: %x, total_len: %x\n\n", td->cerr, td->total_len);
 }
 
 static void ehci_start (hci_t *controller)
@@ -122,7 +122,7 @@ int wait_for_tds(qtd_t *head)
 		if (cur->halted) {
 			printf("ERROR with packet\n");
 			dump_td(virt_to_phys(cur));
-			printf("-----------------\n");
+			debug("-----------------\n");
 			return 1;
 		}
 		if (cur->next_qtd & 1) {
@@ -130,7 +130,7 @@ int wait_for_tds(qtd_t *head)
 		}
 		if (0) dump_td(virt_to_phys(cur));
 		/* helps debugging the TD chain */
-		if (0) printf("\nmoving from %x to %x\n", cur, phys_to_virt(cur->next_qtd));
+		if (0) debug("\nmoving from %x to %x\n", cur, phys_to_virt(cur->next_qtd));
 		cur = phys_to_virt(cur->next_qtd);
 	}
 	return result;
diff --git a/payloads/libpayload/drivers/usb/ehci_rh.c b/payloads/libpayload/drivers/usb/ehci_rh.c
index 5f0db94b8d..22476c16b9 100644
--- a/payloads/libpayload/drivers/usb/ehci_rh.c
+++ b/payloads/libpayload/drivers/usb/ehci_rh.c
@@ -56,7 +56,7 @@ ehci_rh_hand_over_port (usbdev_t *dev, int port)
 	volatile portsc_t *p = &(RH_INST(dev)->ports[port]);
 	volatile portsc_t tmp;
 
-	printf("giving up port %x, it's USB1\n", port+1);
+	debug("giving up port %x, it's USB1\n", port+1);
 
 	/* Lowspeed device. Hand over to companion */
 	tmp = *p;
@@ -76,7 +76,7 @@ ehci_rh_scanport (usbdev_t *dev, int port)
 	volatile portsc_t *p = &(RH_INST(dev)->ports[port]);
 	volatile portsc_t tmp;
 	if (RH_INST(dev)->devices[port]!=-1) {
-		printf("Unregister device at port %x\n", port+1);
+		debug("Unregister device at port %x\n", port+1);
 		usb_detach_device(dev->controller, RH_INST(dev)->devices[port]);
 		RH_INST(dev)->devices[port]=-1;
 	}
@@ -109,7 +109,7 @@ ehci_rh_scanport (usbdev_t *dev, int port)
 			ehci_rh_hand_over_port(dev, port);
 			return;
 		}
-		printf("port %x hosts a USB2 device\n", port+1);
+		debug("port %x hosts a USB2 device\n", port+1);
 		RH_INST(dev)->devices[port] = usb_attach_device(dev->controller, dev->address, port, 2);
 	}
 	/* RW/C register, so clear it by writing 1 */
@@ -153,7 +153,7 @@ ehci_rh_init (usbdev_t *dev)
 	RH_INST(dev)->n_ports = EHCI_INST(dev->controller)->capabilities->n_ports;
 	RH_INST(dev)->ports = EHCI_INST(dev->controller)->operation->portsc;
 
-	printf("root hub has %x ports\n", RH_INST(dev)->n_ports);
+	debug("root hub has %x ports\n", RH_INST(dev)->n_ports);
 
 	RH_INST(dev)->devices = malloc(RH_INST(dev)->n_ports * sizeof(int));
 	for (i=0; i < RH_INST(dev)->n_ports; i++) {
diff --git a/payloads/libpayload/drivers/usb/uhci.c b/payloads/libpayload/drivers/usb/uhci.c
index 1f80c6a3c6..4484e17331 100644
--- a/payloads/libpayload/drivers/usb/uhci.c
+++ b/payloads/libpayload/drivers/usb/uhci.c
@@ -50,14 +50,14 @@ static u8* uhci_poll_intr_queue (void *queue);
 static void
 uhci_dump (hci_t *controller)
 {
-	printf ("dump:\nUSBCMD: %x\n", uhci_reg_read16 (controller, USBCMD));
-	printf ("USBSTS: %x\n", uhci_reg_read16 (controller, USBSTS));
-	printf ("USBINTR: %x\n", uhci_reg_read16 (controller, USBINTR));
-	printf ("FRNUM: %x\n", uhci_reg_read16 (controller, FRNUM));
-	printf ("FLBASEADD: %x\n", uhci_reg_read32 (controller, FLBASEADD));
-	printf ("SOFMOD: %x\n", uhci_reg_read8 (controller, SOFMOD));
-	printf ("PORTSC1: %x\n", uhci_reg_read16 (controller, PORTSC1));
-	printf ("PORTSC2: %x\n", uhci_reg_read16 (controller, PORTSC2));
+	debug ("dump:\nUSBCMD: %x\n", uhci_reg_read16 (controller, USBCMD));
+	debug ("USBSTS: %x\n", uhci_reg_read16 (controller, USBSTS));
+	debug ("USBINTR: %x\n", uhci_reg_read16 (controller, USBINTR));
+	debug ("FRNUM: %x\n", uhci_reg_read16 (controller, FRNUM));
+	debug ("FLBASEADD: %x\n", uhci_reg_read32 (controller, FLBASEADD));
+	debug ("SOFMOD: %x\n", uhci_reg_read8 (controller, SOFMOD));
+	debug ("PORTSC1: %x\n", uhci_reg_read16 (controller, PORTSC1));
+	debug ("PORTSC2: %x\n", uhci_reg_read16 (controller, PORTSC2));
 }
 #endif
 
@@ -80,21 +80,21 @@ td_dump (td_t *td)
 			sprintf(td_value, "%x", td->pid);
 			td_type=td_value;
 	}
-	printf ("%s packet (at %lx) to %x.%x failed\n", td_type,
+	debug ("%s packet (at %lx) to %x.%x failed\n", td_type,
 		virt_to_phys (td), td->dev_addr, td->endp);
-	printf ("td (counter at %x) returns: ", td->counter);
-	printf (" bitstuff err: %x, ", td->status_bitstuff_err);
-	printf (" CRC err: %x, ", td->status_crc_err);
-	printf (" NAK rcvd: %x, ", td->status_nakrcvd);
-	printf (" Babble: %x, ", td->status_babble);
-	printf (" Data Buffer err: %x, ", td->status_databuf_err);
-	printf (" Stalled: %x, ", td->status_stalled);
-	printf (" Active: %x\n", td->status_active);
+	debug ("td (counter at %x) returns: ", td->counter);
+	debug (" bitstuff err: %x, ", td->status_bitstuff_err);
+	debug (" CRC err: %x, ", td->status_crc_err);
+	debug (" NAK rcvd: %x, ", td->status_nakrcvd);
+	debug (" Babble: %x, ", td->status_babble);
+	debug (" Data Buffer err: %x, ", td->status_databuf_err);
+	debug (" Stalled: %x, ", td->status_stalled);
+	debug (" Active: %x\n", td->status_active);
 	if (td->status_babble)
-		printf (" Babble because of %s\n",
+		debug (" Babble because of %s\n",
 			td->status_bitstuff_err ? "host" : "device");
 	if (td->status_active)
-		printf (" still active - timeout?\n");
+		debug (" still active - timeout?\n");
 }
 
 static void
@@ -112,7 +112,7 @@ uhci_reset (hci_t *controller)
 	uhci_reg_write32 (controller, FLBASEADD,
 			  (u32) virt_to_phys (UHCI_INST (controller)->
 					      framelistptr));
-	//printf ("framelist at %p\n",UHCI_INST(controller)->framelistptr);
+	//debug ("framelist at %p\n",UHCI_INST(controller)->framelistptr);
 
 	/* disable irqs */
 	uhci_reg_write16 (controller, USBINTR, 0);
@@ -367,7 +367,7 @@ uhci_control (usbdev_t *dev, direction_t dir, int drlen, void *devreq, int dalen
 	if (td == 0) {
 		result = 0;
 	} else {
-		printf ("control packet, req %x\n", req);
+		debug ("control packet, req %x\n", req);
 		td_dump (td);
 		result = 1;
 	}
diff --git a/payloads/libpayload/drivers/usb/uhci_rh.c b/payloads/libpayload/drivers/usb/uhci_rh.c
index cf5d5a773d..bd3fb42b22 100644
--- a/payloads/libpayload/drivers/usb/uhci_rh.c
+++ b/payloads/libpayload/drivers/usb/uhci_rh.c
@@ -49,7 +49,7 @@ uhci_rh_enable_port (usbdev_t *dev, int port)
 	else if (port == 2)
 		port = PORTSC2;
 	else {
-		printf("Invalid port %d\n", port);
+		debug("Invalid port %d\n", port);
 		return;
 	}
 
@@ -94,7 +94,7 @@ uhci_rh_scanport (usbdev_t *dev, int port)
 		portsc = PORTSC2;
 		offset = 1;
 	} else {
-		printf("Invalid port %d\n", port);
+		debug("Invalid port %d\n", port);
 		return;
 	}
 	int devno = RH_INST (dev)->port[offset];
diff --git a/payloads/libpayload/drivers/usb/usb.c b/payloads/libpayload/drivers/usb/usb.c
index d5f47e47b4..6995cef7b2 100644
--- a/payloads/libpayload/drivers/usb/usb.c
+++ b/payloads/libpayload/drivers/usb/usb.c
@@ -91,7 +91,7 @@ void
 init_device_entry (hci_t *controller, int i)
 {
 	if (controller->devices[i] != 0)
-		printf("warning: device %d reassigned?\n", i);
+		debug("warning: device %d reassigned?\n", i);
 	controller->devices[i] = malloc(sizeof(usbdev_t));
 	controller->devices[i]->controller = controller;
 	controller->devices[i]->address = -1;
@@ -145,7 +145,7 @@ get_descriptor (usbdev_t *dev, unsigned char bmRequestType, int descType,
 	dr.wIndex = langID;
 	dr.wLength = 8;
 	if (dev->controller->control (dev, IN, sizeof (dr), &dr, 8, buf)) {
-		printf ("getting descriptor size (type %x) failed\n",
+		debug ("getting descriptor size (type %x) failed\n",
 			descType);
 	}
 
@@ -169,7 +169,7 @@ get_descriptor (usbdev_t *dev, unsigned char bmRequestType, int descType,
 	dr.wLength = size;
 	if (dev->controller->
 	    control (dev, IN, sizeof (dr), &dr, size, result)) {
-		printf ("getting descriptor (type %x, size %x) failed\n",
+		debug ("getting descriptor (type %x, size %x) failed\n",
 			descType, size);
 	}
 
@@ -218,7 +218,7 @@ get_free_address (hci_t *controller)
 		if (controller->devices[i] == 0)
 			return i;
 	}
-	printf ("no free address found\n");
+	debug ("no free address found\n");
 	return -1;		// no free address
 }
 
@@ -251,7 +251,7 @@ set_address (hci_t *controller, int speed)
 	dev->endpoints[0].direction = SETUP;
 	mdelay (50);
 	if (dev->controller->control (dev, OUT, sizeof (dr), &dr, 0, 0)) {
-		printf ("set_address failed\n");
+		debug ("set_address failed\n");
 		return -1;
 	}
 	mdelay (50);
@@ -260,7 +260,7 @@ set_address (hci_t *controller, int speed)
 		(device_to_host, standard_type, dev_recp), 1, 0, 0);
 	dd = (device_descriptor_t *) dev->descriptor;
 
-	printf ("device 0x%04x:0x%04x is USB %x.%x ",
+	printf ("* found device (0x%04x:0x%04x, USB %x.%x)",
 		 dd->idVendor, dd->idProduct,
 		 dd->bcdUSB >> 8, dd->bcdUSB & 0xff);
 	dev->quirks = usb_quirk_check(dd->idVendor, dd->idProduct);
@@ -364,70 +364,70 @@ set_address (hci_t *controller, int speed)
 		wireless_device   = 0xe0,
 		misc_device       = 0xef,
 	};
-
+	printf(", class: ");
 	switch (class) {
 	case audio_device:
-		printf("(Audio)\n");
+		printf("audio\n");
 		break;
 	case comm_device:
-		printf("(Communication)\n");
+		printf("communication\n");
 		break;
 	case hid_device:
-		printf ("(HID)\n");
+		printf ("HID\n");
 #ifdef CONFIG_USB_HID
 		controller->devices[adr]->init = usb_hid_init;
 #else
-		printf ("NOTICE: USB HID support not compiled in\n");
+		debug ("NOTICE: USB HID support not compiled in\n");
 #endif
 		break;
 	case physical_device:
-		printf("(Physical)\n");
+		printf("physical\n");
 		break;
 	case imaging_device:
-		printf("(Camera)\n");
+		printf("camera\n");
 		break;
 	case printer_device:
-		printf("(Printer)\n");
+		printf("printer\n");
 		break;
 	case msc_device:
-		printf ("(MSC)\n");
+		printf ("MSC\n");
 #ifdef CONFIG_USB_MSC
 		controller->devices[adr]->init = usb_msc_init;
 #else
-		printf ("NOTICE: USB MSC support not compiled in\n");
+		debug ("NOTICE: USB MSC support not compiled in\n");
 #endif
 		break;
 	case hub_device:
-		printf ("(Hub)\n");
+		printf ("hub\n");
 #ifdef CONFIG_USB_HUB
 		controller->devices[adr]->init = usb_hub_init;
 #else
-		printf ("NOTICE: USB hub support not compiled in.\n");
+		debug ("NOTICE: USB hub support not compiled in.\n");
 #endif
 		break;
 	case cdc_device:
-		printf("(CDC)\n");
+		printf("CDC\n");
 		break;
 	case ccid_device:
-		printf ("(Smart Card / CCID)\n");
+		printf("smartcard / CCID\n");
 		break;
 	case security_device:
-		printf("(Content Security)\n");
+		printf("content security\n");
 		break;
 	case video_device:
-		printf("(Video)\n");
+		printf("video\n");
 		break;
 	case healthcare_device:
-		printf("(Healthcare)\n");
+		printf("healthcare\n");
 		break;
 	case diagnostic_device:
-		printf("(Diagnostic)\n");
+		printf("diagnostic\n");
 		break;
 	case wireless_device:
-		printf("(Wireless)\n");
+		printf("wireless\n");
 		break;
 	default:
-		printf ("(unsupported class %x)\n", class);
+		printf("unsupported class %x\n", class);
 		break;
 	}
 	return adr;
@@ -445,7 +445,7 @@ int
 usb_attach_device(hci_t *controller, int hubaddress, int port, int speed)
 {
 	static const char* speeds[] = { "full", "low", "high" };
-	printf ("%sspeed device\n", (speed <= 2) ? speeds[speed] : "invalid value - no");
+	debug ("%sspeed device\n", (speed <= 2) ? speeds[speed] : "invalid value - no");
 	int newdev = set_address (controller, speed);
 	if (newdev == -1)
 		return -1;
diff --git a/payloads/libpayload/drivers/usb/usbhid.c b/payloads/libpayload/drivers/usb/usbhid.c
index bf3ec1e407..57f60cfe80 100644
--- a/payloads/libpayload/drivers/usb/usbhid.c
+++ b/payloads/libpayload/drivers/usb/usbhid.c
@@ -37,9 +37,7 @@ typedef enum { hid_proto_boot = 0, hid_proto_report = 1 } hid_proto;
 enum { hid_boot_proto_none = 0, hid_boot_proto_keyboard =
 		1, hid_boot_proto_mouse = 2
 };
-#ifdef USB_DEBUG
 static const char *boot_protos[3] = { "(none)", "keyboard", "mouse" };
-#endif
 enum { GET_REPORT = 0x1, GET_IDLE = 0x2, GET_PROTOCOL = 0x3, SET_REPORT =
 		0x9, SET_IDLE = 0xa, SET_PROTOCOL = 0xb
 };
@@ -394,7 +392,7 @@ static int usb_hid_set_layout (const char *country)
 		return 0;
 	}
 
-	printf("Keyboard layout '%s' not found, using '%s'\n",
+	printf("  Keyboard layout '%s' not found, using '%s'\n",
 			country, map->country);
 
 	/* Nothing found, not changed */
@@ -438,7 +436,7 @@ usb_hid_init (usbdev_t *dev)
 			/* 35 countries defined: */
 			if (countrycode > 35)
 				countrycode = 0;
-			printf ("  Keyboard has %s layout (country code %02x)\n",
+			debug ("  Keyboard has %s layout (country code %02x)\n",
 					countries[countrycode][0], countrycode);
 
 			/* Set keyboard layout accordingly */
@@ -464,7 +462,7 @@ usb_hid_init (usbdev_t *dev)
 			debug ("  configuration done.\n");
 			break;
 		case hid_boot_proto_mouse:
-			printf("NOTICE: USB mice are not supported.\n");
+			debug("NOTICE: USB mice are not supported.\n");
 			break;
 		}
 	}
diff --git a/payloads/libpayload/drivers/usb/usbinit.c b/payloads/libpayload/drivers/usb/usbinit.c
index d3cfbb75e1..3964197038 100644
--- a/payloads/libpayload/drivers/usb/usbinit.c
+++ b/payloads/libpayload/drivers/usb/usbinit.c
@@ -72,38 +72,38 @@ usb_controller_initialize (int bus, int dev, int func)
 			pciid >> 16, pciid & 0xFFFF, func);
 		switch(prog_if) {
 			case 0x00:
-				printf ("UHCI controller\n");
 #ifdef CONFIG_USB_UHCI
+				printf ("UHCI controller\n");
 				uhci_init (addr);
 #else
-				printf ("Not supported.\n");
+				printf ("UHCI controller (not supported)\n");
 #endif
 				break;
 
 			case 0x10:
-				printf ("OHCI controller\n");
 #ifdef CONFIG_USB_OHCI
+				printf ("OHCI controller\n");
 				ohci_init(addr);
 #else
-				printf ("Not supported.\n");
+				printf ("OHCI controller (not supported)\n");
 #endif
 				break;
 
 			case 0x20:
-				printf ("EHCI controller\n");
 #ifdef CONFIG_USB_EHCI
+				printf ("EHCI controller\n");
 				ehci_init(addr);
 #else
-				printf ("Not supported.\n");
+				printf ("EHCI controller (not supported)\n");
 #endif
 				break;
 
 			case 0x30:
-				printf ("xHCI controller\n");
 #ifdef CONFIG_USB_XHCI
+				printf ("xHCI controller\n");
 				xhci_init(addr);
 #else
-				printf ("Not supported.\n");
+				printf ("xHCI controller (not supported)\n");
 #endif
 				break;
 
diff --git a/payloads/libpayload/drivers/usb/usbmsc.c b/payloads/libpayload/drivers/usb/usbmsc.c
index 6658f2ca5c..729bf91171 100644
--- a/payloads/libpayload/drivers/usb/usbmsc.c
+++ b/payloads/libpayload/drivers/usb/usbmsc.c
@@ -343,7 +343,7 @@ read_capacity (usbdev_t *dev)
 	cb.command = 0x25;	// read capacity
 	u8 buf[8];
 
-	printf ("Reading capacity of mass storage device.\n");
+	debug ("Reading capacity of mass storage device.\n");
 	int count = 0;
 	while ((count++ < 20)
 	       &&
@@ -352,15 +352,16 @@ read_capacity (usbdev_t *dev)
 		 8) == 1));
 	if (count >= 20) {
 		// still not successful, assume 2tb in 512byte sectors, which is just the same garbage as any other number, but probably more usable.
-		printf ("Assuming 2TB in 512byte sectors as READ CAPACITY didn't answer.\n");
+		printf ("  assuming 2 TB with 512-byte sectors as READ CAPACITY didn't answer.\n");
 		MSC_INST (dev)->numblocks = 0xffffffff;
 		MSC_INST (dev)->blocksize = 512;
 	} else {
 		MSC_INST (dev)->numblocks = ntohl (*(u32 *) buf) + 1;
 		MSC_INST (dev)->blocksize = ntohl (*(u32 *) (buf + 4));
 	}
-	printf ("  has %d blocks sized %db\n", MSC_INST (dev)->numblocks,
-		MSC_INST (dev)->blocksize);
+	printf ("  %d %d-byte sectors (%d MB)\n", MSC_INST (dev)->numblocks,
+		MSC_INST (dev)->blocksize,
+		MSC_INST (dev)->numblocks * MSC_INST (dev)->blocksize / 1000 / 1000);
 }
 
 void
@@ -376,9 +377,9 @@ usb_msc_init (usbdev_t *dev)
 	interface_descriptor_t *interface =
 		(interface_descriptor_t *) (((char *) cd) + cd->bLength);
 
-	printf ("  it uses %s command set\n",
+	debug ("  it uses %s command set\n",
 		msc_subclass_strings[interface->bInterfaceSubClass]);
-	printf ("  it uses %s protocol\n",
+	debug ("  it uses %s protocol\n",
 		msc_protocol_strings[interface->bInterfaceProtocol]);
 
 
@@ -420,13 +421,13 @@ usb_msc_init (usbdev_t *dev)
 		fatal ("couldn't find bulk-in endpoint");
 	if (MSC_INST (dev)->bulk_out == 0)
 		fatal ("couldn't find bulk-out endpoint");
-	printf ("  using endpoint %x as in, %x as out\n",
+	debug ("  using endpoint %x as in, %x as out\n",
 		MSC_INST (dev)->bulk_in->endpoint,
 		MSC_INST (dev)->bulk_out->endpoint);
 
-	printf ("  has %d luns\n", get_max_luns (dev) + 1);
+	debug ("  has %d luns\n", get_max_luns (dev) + 1);
 
-	printf ("  Waiting for device to become ready... ");
+	printf ("  Waiting for device to become ready...");
 	timeout = 30 * 10; /* SCSI/ATA specs say we have to wait up to 30s. Ugh */
 	while (test_unit_ready (dev) && --timeout) {
 		mdelay (100);
@@ -439,16 +440,16 @@ usb_msc_init (usbdev_t *dev)
 		printf ("ok.\n");
 	}
 
-	printf ("  spin up");
+	debug ("  spin up");
 	for (i = 0; i < 30; i++) {
-		printf (".");
+		debug (".");
 		if (!spin_up (dev)) {
-			printf (" OK.");
+			debug (" OK.");
 			break;
 		}
 		mdelay (100);
 	}
-	printf ("\n");
+	debug ("\n");
 
 	read_capacity (dev);
 	if (usbdisk_create)