Index: uspace/drv/bus/usb/ehci/ehci_rh.c
===================================================================
--- uspace/drv/bus/usb/ehci/ehci_rh.c	(revision 34c9cfc553adde7b9a5ac6552f5884cbc95e78a6)
+++ uspace/drv/bus/usb/ehci/ehci_rh.c	(revision 605db7f480d964cda088892b1a8309a88a4e3f03)
@@ -106,11 +106,13 @@
 	    (EHCI_RD(caps->hcsparams) >> EHCI_CAPS_HCS_N_PORTS_SHIFT) &
 	    EHCI_CAPS_HCS_N_PORTS_MASK;
-	usb_log_debug2("hcsparams: %x.\n", EHCI_RD(caps->hcsparams));
-	usb_log_info("%s: Found %u ports.\n", name, instance->port_count);
+	usb_log_debug2("RH(%p): hcsparams: %x.\n", instance,
+	    EHCI_RD(caps->hcsparams));
+	usb_log_info("RH(%p): Found %u ports.\n", instance,
+	    instance->port_count);
 
 	if (EHCI_RD(caps->hcsparams) & EHCI_CAPS_HCS_PPC_FLAG) {
-		usb_log_info("%s: Per-port power switching.\n", name);
+		usb_log_info("RH(%p): Per-port power switching.", instance);
 	} else {
-		usb_log_info("%s: No power switching.\n", name);
+		usb_log_info("RH(%p): No power switching.", instance);
 	}
 
@@ -146,5 +148,5 @@
 	    batch->buffer, batch->buffer_size, &batch->transfered_size);
 	if (batch->error == ENAK) {
-		usb_log_debug("EHCI RH(%p): BATCH(%p) adding as unfinished\n",
+		usb_log_debug("RH(%p): BATCH(%p) adding as unfinished",
 		    instance, batch);
 		/* This is safe because only status change interrupt transfers
@@ -156,5 +158,5 @@
 		usb_transfer_batch_finish(batch, NULL);
 		usb_transfer_batch_destroy(batch);
-		usb_log_debug("EHCI RH(%p): BATCH(%p) virtual request: %s\n",
+		usb_log_debug("RH(%p): BATCH(%p) virtual request complete: %s",
 		    instance, batch, str_error(batch->error));
 	}
@@ -174,4 +176,6 @@
 	usb_transfer_batch_t *batch = instance->unfinished_interrupt_transfer;
 	instance->unfinished_interrupt_transfer = NULL;
+	usb_log_debug2("RH(%p): Interrupt. Processing batch: %p",
+	    instance, batch);
 	if (batch) {
 		const usb_target_t target = {{
@@ -290,5 +294,6 @@
 	);
 	/* Note feature numbers for test and indicator feature do not
-	 * corespond to the port status bit locations */
+	 * correspond to the port status bit locations */
+	usb_log_debug2("RH(%p-%u) port status: %"PRIx32, hub, port, status);
 	memcpy(data, &status, sizeof(status));
 	*act_size = sizeof(status);
@@ -305,5 +310,5 @@
 	ehci_rh_job_t *job = arg;
 	async_usleep(50000);
-	usb_log_debug("EHCI_RH(%p-%u): Clearing reset", job->hub, job->port);
+	usb_log_debug("RH(%p-%u): Clearing reset", job->hub, job->port);
 	EHCI_CLR(job->hub->registers->portsc[job->port],
 	    USB_PORTSC_PORT_RESET_FLAG);
@@ -313,10 +318,10 @@
 		async_usleep(1);
 	};
-	usb_log_debug("EHCI_RH(%p-%u): Reset complete", job->hub, job->port);
+	usb_log_debug("RH(%p-%u): Reset complete", job->hub, job->port);
 	/* Handle port ownership, if the port is not enabled
 	 * after reset it's a full speed device */
 	if (!(EHCI_RD(job->hub->registers->portsc[job->port]) &
 	    USB_PORTSC_ENABLED_FLAG)) {
-		usb_log_debug("EHCI_RH(%p-%u): Port not enabled after reset, "
+		usb_log_debug("RH(%p-%u): Port not enabled after reset, "
 		"giving up ownership", job->hub, job->port);
 		EHCI_SET(job->hub->registers->portsc[job->port],
@@ -334,4 +339,5 @@
 	ehci_rh_job_t *job = arg;
 	async_usleep(20000);
+	usb_log_debug("RH(%p-%u): Stopping resume", job->hub, job->port);
 	EHCI_CLR(job->hub->registers->portsc[job->port],
 	    USB_PORTSC_RESUME_FLAG);
@@ -355,4 +361,5 @@
 	}
 	fibril_add_ready(fib);
+	usb_log_debug2("RH(%p-%u): Scheduled delayed stop job.", rh, port);
 	return EOK;
 }
@@ -379,4 +386,5 @@
 	{
 	case USB_HUB_FEATURE_PORT_POWER:          /*8*/
+		usb_log_debug2("RH(%p-%u): Clear port power.", hub, port);
 		EHCI_CLR(hub->registers->portsc[port],
 		    USB_PORTSC_PORT_POWER_FLAG);
@@ -384,4 +392,5 @@
 
 	case USB_HUB_FEATURE_PORT_ENABLE:         /*1*/
+		usb_log_debug2("RH(%p-%u): Clear port enable.", hub, port);
 		EHCI_CLR(hub->registers->portsc[port],
 		    USB_PORTSC_ENABLED_FLAG);
@@ -389,4 +398,5 @@
 
 	case USB_HUB_FEATURE_PORT_SUSPEND:        /*2*/
+		usb_log_debug2("RH(%p-%u): Clear port suspend.", hub, port);
 		/* If not in suspend it's noop */
 		if ((EHCI_RD(hub->registers->portsc[port]) &
@@ -396,27 +406,39 @@
 		EHCI_SET(hub->registers->portsc[port],
 		    USB_PORTSC_RESUME_FLAG);
-		delayed_job(stop_resume, hub, port);
-		return EOK;
+		//TODO: What if creating the delayed job fails?
+		return delayed_job(stop_resume, hub, port);
 
 	case USB_HUB_FEATURE_C_PORT_CONNECTION:   /*16*/
+		usb_log_debug2("RH(%p-%u): Clear port connection change.",
+		    hub, port);
 		EHCI_SET(hub->registers->portsc[port],
 		    USB_PORTSC_CONNECT_CH_FLAG);
 		return EOK;
 	case USB_HUB_FEATURE_C_PORT_ENABLE:       /*17*/
+		usb_log_debug2("RH(%p-%u): Clear port enable change.",
+		    hub, port);
 		EHCI_SET(hub->registers->portsc[port],
 		    USB_PORTSC_CONNECT_CH_FLAG);
 		return EOK;
 	case USB_HUB_FEATURE_C_PORT_OVER_CURRENT: /*19*/
+		usb_log_debug2("RH(%p-%u): Clear port OC change.",
+		    hub, port);
 		EHCI_SET(hub->registers->portsc[port],
 		    USB_PORTSC_OC_CHANGE_FLAG);
 		return EOK;
 	case USB_HUB_FEATURE_C_PORT_SUSPEND:      /*18*/
+		usb_log_debug2("RH(%p-%u): Clear port suspend change.",
+		    hub, port);
 		hub->resume_flag[port] = false;
 		return EOK;
 	case USB_HUB_FEATURE_C_PORT_RESET:        /*20*/
+		usb_log_debug2("RH(%p-%u): Clear port reset change.",
+		    hub, port);
 		hub->reset_flag[port] = false;
 		return EOK;
 
 	default:
+		usb_log_warning("RH(%p-%u): Clear unknown feature: %u",
+		    hub, port, feature);
 		return ENOTSUP;
 	}
@@ -441,21 +463,27 @@
 	switch (feature) {
 	case USB_HUB_FEATURE_PORT_ENABLE:  /*1*/
+		usb_log_debug2("RH(%p-%u): Set port enable.", hub, port);
 		EHCI_SET(hub->registers->portsc[port],
 		    USB_PORTSC_ENABLED_FLAG);
 		return EOK;
 	case USB_HUB_FEATURE_PORT_SUSPEND: /*2*/
+		usb_log_debug2("RH(%p-%u): Set port suspend.", hub, port);
 		EHCI_SET(hub->registers->portsc[port],
 		    USB_PORTSC_SUSPEND_FLAG);
 		return EOK;
 	case USB_HUB_FEATURE_PORT_RESET:   /*4*/
+		usb_log_debug2("RH(%p-%u): Set port reset.", hub, port);
 		EHCI_SET(hub->registers->portsc[port],
 		    USB_PORTSC_PORT_RESET_FLAG);
-		delayed_job(stop_reset, hub, port);
-		return EOK;
+		//TODO: What if creating the delayed job fails?
+		return delayed_job(stop_reset, hub, port);
 	case USB_HUB_FEATURE_PORT_POWER:   /*8*/
+		usb_log_debug2("RH(%p-%u): Set port power.", hub, port);
 		EHCI_SET(hub->registers->portsc[port],
 		    USB_PORTSC_PORT_POWER_FLAG);
 		return EOK;
 	default:
+		usb_log_warning("RH(%p-%u): Set unknown feature: %u",
+		    hub, port, feature);
 		return ENOTSUP;
 	}
@@ -501,5 +529,5 @@
 	}
 
-	usb_log_debug2("EHCI root hub interrupt mask: %hx.\n", mask);
+	usb_log_debug2("RH(%p): root hub interrupt mask: %"PRIx16, hub, mask);
 
 	if (mask == 0)