[PATCH 0/2] usb hcd console polling and sysrq tasklet

[PATCH 0/2] usb hcd console polling and sysrq tasklet

[Jason Wessel]

This is a version 2 of the patch set to the original usb_debug patches
which contained a polling loop to forcibly poll the usb hcd device.

The original patch made use of the polling regardless whether it was
the tty driver path or the console path, which was not desired.

The serial uart code implements the console writes synchronously such
that you get the data right away and "pay the toll" in terms of system
performance loss if you do lots of printk's to the console.  The usb
serial console code just eats the data if there is no room left in the
queue, and you do not see the data until the interrupts are restored.

If we assume the main reason you would use a usb console device is to
get printk's then every effort should be made to be able to see the
printk's on the usb console device.  In this patch series, two
conditions must be met before the hcd device would get polled.

1) The data write is a usb serial console write
2) The usb serial driver has set the variable max_in_flight_urbs

Based on Alan's comments about the 1ms minimum response time for the
hcd device I ended up using a maximum 3ms delay loop.  The 3ms was
selected based on testing the usb_debug device and the ftdi usb rs232
port.  I found the usb_debug device needed the 1ms and the ftdi device
required slightly more than 2ms else there was some sporadic data
loss.  Perhaps we can decide if this approach is any more or less
reasonable...

I also tested incurring the penalty 3ms for each write with the device
in a "failed" capacity.  In that case it introduced a 3ms delay for
each printk() which only showed any noticible delay with the "SysRq t"
packet.

The second patch in the series changes the sysrq handler to execute in
a tasklet.  I found that the hcd device lock was always held while the
driver call backs were executed, and that poses a problem that you
cannot get the sysrq printk's out to the usb console device after the
in_flight urb queue is filled.

Using these patches on top of the 4 that Greg K-H already accepted I
found that the usb serial console worked for a number of debug
circumstances where it does not work at all today, including reporting
an oops after conole init and prior to the execution of the init
process.

Thanks,
Jason.


The short log and git info is below, which is against the 2.6.30
development tree + the 4 accepted patches


git://git.kernel.org/pub/scm/linux/kernel/git/jwessel/linux-2.6-kgdb.git for_gregkh_2


Jason Wessel (2):
      usb hcd: poll hcd device to force writes
      usb_serial: Run the sysrq handler in a tasklet

 drivers/usb/core/hcd.c         |   15 +++++++++++++
 drivers/usb/core/hcd.h         |    1 +
 drivers/usb/serial/console.c   |   44 ++++++++++++++++++++++++++-------------
 drivers/usb/serial/ftdi_sio.c  |    7 +++--
 drivers/usb/serial/generic.c   |   33 +++++++++++++++++++++++++++++-
 drivers/usb/serial/usb_debug.c |    2 +-
 6 files changed, 82 insertions(+), 20 deletions(-)

[PATCH 1/2] usb hcd: poll hcd device to force writes

[Jason Wessel]

The problem that this patch tries to solve is that data is lost
because there are too many outstanding transmit urb's while trying to
execute printk's to a console.  The same is true if you try something
like "echo t > /proc/sysrq-trigger".

This patch takes the route of forcibly polling the hcd device to drain
the urb queue in order to initiate the bulk write call backs.  This
only happens if the device is a usb serial console device that sets
the max_in_flight_urbs in the serial device structure.

A maximum 3 ms penalty will get incurred to allow the hcd controller
to complete a write urb, else the console data is thrown away.

The max_in_flight_urbs was reduced in the usb_debug driver because it
is highly desired to push things out to the console in a timely
fashion and there is no need to have a queue that large for the
interrupt driven mode of operation when used through the tty
interface.

Signed-off-by: Jason Wessel <jason.wessel@windriver.com>
---
 drivers/usb/core/hcd.c         |   15 +++++++++++++
 drivers/usb/core/hcd.h         |    1 +
 drivers/usb/serial/console.c   |   44 ++++++++++++++++++++++++++-------------
 drivers/usb/serial/ftdi_sio.c  |    7 +++--
 drivers/usb/serial/usb_debug.c |    2 +-
 5 files changed, 50 insertions(+), 19 deletions(-)

diff --git a/drivers/usb/core/hcd.c b/drivers/usb/core/hcd.c
index 42b93da..ca15008 100644
--- a/drivers/usb/core/hcd.c
+++ b/drivers/usb/core/hcd.c
@@ -1760,6 +1760,7 @@ irqreturn_t usb_hcd_irq (int irq, void *__hcd)
 	local_irq_restore(flags);
 	return rc;
 }
+EXPORT_SYMBOL_GPL(usb_hcd_irq);
 
 /*-------------------------------------------------------------------------*/
 
@@ -2045,6 +2046,20 @@ usb_hcd_platform_shutdown(struct platform_device* dev)
 }
 EXPORT_SYMBOL_GPL(usb_hcd_platform_shutdown);
 
+void
+usb_hcd_poll_urb_irq(struct urb *urb)
+{
+	struct usb_hcd *hcd;
+
+	if (!urb)
+		return;
+
+	hcd = bus_to_hcd(urb->dev->bus);
+	if (hcd)
+		usb_hcd_irq(0, hcd);
+}
+EXPORT_SYMBOL_GPL(usb_hcd_poll_urb_irq);
+
 /*-------------------------------------------------------------------------*/
 
 #if defined(CONFIG_USB_MON) || defined(CONFIG_USB_MON_MODULE)
diff --git a/drivers/usb/core/hcd.h b/drivers/usb/core/hcd.h
index e7d4479..30e0373 100644
--- a/drivers/usb/core/hcd.h
+++ b/drivers/usb/core/hcd.h
@@ -251,6 +251,7 @@ extern void usb_put_hcd(struct usb_hcd *hcd);
 extern int usb_add_hcd(struct usb_hcd *hcd,
 		unsigned int irqnum, unsigned long irqflags);
 extern void usb_remove_hcd(struct usb_hcd *hcd);
+extern void usb_hcd_poll_urb_irq(struct urb *urb);
 
 struct platform_device;
 extern void usb_hcd_platform_shutdown(struct platform_device *dev);
diff --git a/drivers/usb/serial/console.c b/drivers/usb/serial/console.c
index 19e2404..ca05e9d 100644
--- a/drivers/usb/serial/console.c
+++ b/drivers/usb/serial/console.c
@@ -18,6 +18,7 @@
 #include <linux/console.h>
 #include <linux/usb.h>
 #include <linux/usb/serial.h>
+#include "../core/hcd.h"
 
 static int debug;
 
@@ -185,13 +186,38 @@ reset_open_count:
 goto out;
 }
 
+static void usb_do_console_write(struct usb_serial *serial,
+				 struct usb_serial_port *port,
+				 const char *buf, unsigned count)
+{
+	int retval;
+	int loops = 3;
+try_again:
+	/* pass on to the driver specific version of this function if
+	   it is available */
+	if (serial->type->write)
+		retval = serial->type->write(NULL, port, buf, count);
+	else
+		retval = usb_serial_generic_write(NULL, port, buf, count);
+	if (serial->type->max_in_flight_urbs && loops-- &&
+	    retval >= 0 && retval < count) {
+		/* poll the hcd device because the queue is full and
+		 * try this for a total of 3 ms and give up. */
+		count -= retval;
+		buf += retval;
+		mdelay(1);
+		usb_hcd_poll_urb_irq(port->read_urb);
+		goto try_again;
+	}
+	dbg("%s - return value : %d", __func__, retval);
+}
+
 static void usb_console_write(struct console *co,
 					const char *buf, unsigned count)
 {
 	static struct usbcons_info *info = &usbcons_info;
 	struct usb_serial_port *port = info->port;
 	struct usb_serial *serial;
-	int retval = -ENODEV;
 
 	if (!port || port->serial->dev->state == USB_STATE_NOTATTACHED)
 		return;
@@ -218,23 +244,11 @@ static void usb_console_write(struct console *co,
 				break;
 			}
 		}
-		/* pass on to the driver specific version of this function if
-		   it is available */
-		if (serial->type->write)
-			retval = serial->type->write(NULL, port, buf, i);
-		else
-			retval = usb_serial_generic_write(NULL, port, buf, i);
-		dbg("%s - return value : %d", __func__, retval);
+		usb_do_console_write(serial, port, buf, i);
 		if (lf) {
 			/* append CR after LF */
 			unsigned char cr = 13;
-			if (serial->type->write)
-				retval = serial->type->write(NULL,
-								port, &cr, 1);
-			else
-				retval = usb_serial_generic_write(NULL,
-								port, &cr, 1);
-			dbg("%s - return value : %d", __func__, retval);
+			usb_do_console_write(serial, port, &cr, 1);
 		}
 		buf += i;
 		count -= i;
diff --git a/drivers/usb/serial/ftdi_sio.c b/drivers/usb/serial/ftdi_sio.c
index a93b76a..a552751 100644
--- a/drivers/usb/serial/ftdi_sio.c
+++ b/drivers/usb/serial/ftdi_sio.c
@@ -51,6 +51,9 @@
 #define DRIVER_AUTHOR "Greg Kroah-Hartman <greg@kroah.com>, Bill Ryder <bryder@sgi.com>, Kuba Ober <kuba@mareimbrium.org>"
 #define DRIVER_DESC "USB FTDI Serial Converters Driver"
 
+/* number of outstanding urbs to prevent userspace DoS from happening */
+#define URB_UPPER_LIMIT	42
+
 static int debug;
 static __u16 vendor = FTDI_VID;
 static __u16 product;
@@ -771,6 +774,7 @@ static struct usb_serial_driver ftdi_sio_device = {
 	.set_termios =		ftdi_set_termios,
 	.break_ctl =		ftdi_break_ctl,
 	.shutdown =		ftdi_shutdown,
+	.max_in_flight_urbs =	URB_UPPER_LIMIT,
 };
 
 
@@ -781,9 +785,6 @@ static struct usb_serial_driver ftdi_sio_device = {
 #define HIGH 1
 #define LOW 0
 
-/* number of outstanding urbs to prevent userspace DoS from happening */
-#define URB_UPPER_LIMIT	42
-
 /*
  * ***************************************************************************
  * Utility functions
diff --git a/drivers/usb/serial/usb_debug.c b/drivers/usb/serial/usb_debug.c
index 6148009..d33df1c 100644
--- a/drivers/usb/serial/usb_debug.c
+++ b/drivers/usb/serial/usb_debug.c
@@ -15,7 +15,7 @@
 #include <linux/usb.h>
 #include <linux/usb/serial.h>
 
-#define URB_DEBUG_MAX_IN_FLIGHT_URBS	4000
+#define URB_DEBUG_MAX_IN_FLIGHT_URBS	42
 #define USB_DEBUG_MAX_PACKET_SIZE	8
 #define USB_DEBUG_BRK_SIZE		8
 static char USB_DEBUG_BRK[USB_DEBUG_BRK_SIZE] = {
-- 
1.6.3.9.g6345d

[PATCH 2/2] usb_serial: Run the sysrq handler in a tasklet

[Jason Wessel]

If a sysrq is processed on the while holding the usb hcd lock, it is
impossible to drain the queue of urbs via the polling interface and
all the printk output is lost.

Using a tasklet to schedule the sysrq allows the hcd device lock to
free up.

Signed-off-by: Jason Wessel <jason.wessel@windriver.com>
---
 drivers/usb/serial/generic.c |   33 ++++++++++++++++++++++++++++++++-
 1 files changed, 32 insertions(+), 1 deletions(-)

diff --git a/drivers/usb/serial/generic.c b/drivers/usb/serial/generic.c
index df56ed3..7554d71 100644
--- a/drivers/usb/serial/generic.c
+++ b/drivers/usb/serial/generic.c
@@ -527,11 +527,42 @@ void usb_serial_generic_unthrottle(struct tty_struct *tty)
 	}
 }
 
+#ifdef CONFIG_MAGIC_SYSRQ
+/* The sysrq tasklet is used to make the sysrq request not occur with
+ * the hcd device lock held.
+ */
+static struct usb_sysrq_data {
+	struct tty_struct *tty;
+	unsigned int ch;
+	int pending;
+} priv_usb_sysrq;
+
+static void usb_sysrq_task(unsigned long args)
+{
+	handle_sysrq(priv_usb_sysrq.ch, priv_usb_sysrq.tty);
+	priv_usb_sysrq.pending = 0;
+}
+static DECLARE_TASKLET(usb_sysrq_tasklet, usb_sysrq_task, 0);
+
+void usb_serial_generic_sysrq_invoke(struct usb_serial_port *port,
+				     unsigned int ch)
+{
+	if (priv_usb_sysrq.pending)
+		return;
+	priv_usb_sysrq.pending = 1;
+	priv_usb_sysrq.ch = ch;
+	priv_usb_sysrq.tty = tty_port_tty_get(&port->port);
+	tasklet_schedule(&usb_sysrq_tasklet);
+}
+#else
+static void usb_serial_generic_sysrq_invoke() {}
+#endif /* CONFIG_SYSRQ */
+
 int usb_serial_handle_sysrq_char(struct usb_serial_port *port, unsigned int ch)
 {
 	if (port->sysrq) {
 		if (ch && time_before(jiffies, port->sysrq)) {
-			handle_sysrq(ch, tty_port_tty_get(&port->port));
+			usb_serial_generic_sysrq_invoke(port, ch);
 			port->sysrq = 0;
 			return 1;
 		}
-- 
1.6.3.9.g6345d

Re: [PATCH 1/2] usb hcd: poll hcd device to force writes

[Alan Stern]

On Tue, 12 May 2009, Jason Wessel wrote:

> This patch takes the route of forcibly polling the hcd device to drain
> the urb queue in order to initiate the bulk write call backs.  This
> only happens if the device is a usb serial console device that sets
> the max_in_flight_urbs in the serial device structure.

> +void
> +usb_hcd_poll_urb_irq(struct urb *urb)
> +{
> +	struct usb_hcd *hcd;
> +
> +	if (!urb)
> +		return;

Is this test really needed?  The routine is called from only one spot, 
after all.  It seems more likely that urb will point to deallocated 
memory than that it will be NULL.  Do you protect against this in 
usb_do_console_write?

Maybe you should pass a pointer to a usb_bus structure rather than an
URB.  Then none of these issues would arise.

> +
> +	hcd = bus_to_hcd(urb->dev->bus);
> +	if (hcd)
> +		usb_hcd_irq(0, hcd);

This test too looks strange, since it can never fail.  (See the 
definition of bus_to_hcd to find out why...)

Alan Stern

Re: [PATCH 1/2] usb hcd: poll hcd device to force writes

[Jason Wessel]

[-- Attachment #1: Type: text/plain, Size: 590 bytes --]

Alan Stern wrote:
> On Tue, 12 May 2009, Jason Wessel wrote:
>
>   
>> +	if (!urb)
>> +		return;
>>     
>
> Is this test really needed?  
Doesn't look like it.
>
> Maybe you should pass a pointer to a usb_bus structure rather than an
> URB.  Then none of these issues would arise.
>
>   

I changed it to pass in the device instead (see attached)

>> +
>> +	hcd = bus_to_hcd(urb->dev->bus);
>> +	if (hcd)
>> +		usb_hcd_irq(0, hcd);
>>     
>
> This test too looks strange, since it can never fail.  (See the 
> definition of bus_to_hcd to find out why...)
>   

I agree.

Thanks,
Jason.



[-- Attachment #2: poll_hcd_device.patch --]
[-- Type: text/x-diff, Size: 6056 bytes --]

From: Jason Wessel <jason.wessel@windriver.com>
Date: Wed, 11 Feb 2009 18:46:32 -0600
Subject: [PATCH] usb hcd: poll hcd device to force writes

The problem that this patch tries to solve is that data is lost
because there are too many outstanding transmit urb's while trying to
execute printk's to a console.  The same is true if you try something
like "echo t > /proc/sysrq-trigger".

This patch takes the route of forcibly polling the hcd device to drain
the urb queue in order to initiate the bulk write call backs.  This
only happens if the device is a usb serial console device that sets
the max_in_flight_urbs in the serial device structure.

A maximum 3 ms penalty will get incurred to allow the hcd controller
to complete a write urb, else the console data is thrown away.

The max_in_flight_urbs was reduced in the usb_debug driver because it
is highly desired to push things out to the console in a timely
fashion and there is no need to have a queue that large for the
interrupt driven mode of operation when used through the tty
interface.

Signed-off-by: Jason Wessel <jason.wessel@windriver.com>

---
 drivers/usb/core/hcd.c         |   11 ++++++++++
 drivers/usb/core/hcd.h         |    1 
 drivers/usb/serial/console.c   |   44 +++++++++++++++++++++++++++--------------
 drivers/usb/serial/ftdi_sio.c  |    7 +++---
 drivers/usb/serial/usb_debug.c |    2 -
 5 files changed, 46 insertions(+), 19 deletions(-)

--- a/drivers/usb/serial/usb_debug.c
+++ b/drivers/usb/serial/usb_debug.c
@@ -15,7 +15,7 @@
 #include <linux/usb.h>
 #include <linux/usb/serial.h>
 
-#define URB_DEBUG_MAX_IN_FLIGHT_URBS	4000
+#define URB_DEBUG_MAX_IN_FLIGHT_URBS	42
 #define USB_DEBUG_MAX_PACKET_SIZE	8
 #define USB_DEBUG_BRK_SIZE		8
 static char USB_DEBUG_BRK[USB_DEBUG_BRK_SIZE] = {
--- a/drivers/usb/core/hcd.c
+++ b/drivers/usb/core/hcd.c
@@ -1760,6 +1760,7 @@ irqreturn_t usb_hcd_irq (int irq, void *
 	local_irq_restore(flags);
 	return rc;
 }
+EXPORT_SYMBOL_GPL(usb_hcd_irq);
 
 /*-------------------------------------------------------------------------*/
 
@@ -2045,6 +2046,16 @@ usb_hcd_platform_shutdown(struct platfor
 }
 EXPORT_SYMBOL_GPL(usb_hcd_platform_shutdown);
 
+void
+usb_hcd_poll_irq(struct usb_device *udev)
+{
+	struct usb_hcd *hcd;
+
+	hcd = bus_to_hcd(udev->bus);
+	usb_hcd_irq(0, hcd);
+}
+EXPORT_SYMBOL_GPL(usb_hcd_poll_irq);
+
 /*-------------------------------------------------------------------------*/
 
 #if defined(CONFIG_USB_MON) || defined(CONFIG_USB_MON_MODULE)
--- a/drivers/usb/serial/ftdi_sio.c
+++ b/drivers/usb/serial/ftdi_sio.c
@@ -51,6 +51,9 @@
 #define DRIVER_AUTHOR "Greg Kroah-Hartman <greg@kroah.com>, Bill Ryder <bryder@sgi.com>, Kuba Ober <kuba@mareimbrium.org>"
 #define DRIVER_DESC "USB FTDI Serial Converters Driver"
 
+/* number of outstanding urbs to prevent userspace DoS from happening */
+#define URB_UPPER_LIMIT	42
+
 static int debug;
 static __u16 vendor = FTDI_VID;
 static __u16 product;
@@ -771,6 +774,7 @@ static struct usb_serial_driver ftdi_sio
 	.set_termios =		ftdi_set_termios,
 	.break_ctl =		ftdi_break_ctl,
 	.shutdown =		ftdi_shutdown,
+	.max_in_flight_urbs =	URB_UPPER_LIMIT,
 };
 
 
@@ -781,9 +785,6 @@ static struct usb_serial_driver ftdi_sio
 #define HIGH 1
 #define LOW 0
 
-/* number of outstanding urbs to prevent userspace DoS from happening */
-#define URB_UPPER_LIMIT	42
-
 /*
  * ***************************************************************************
  * Utility functions
--- a/drivers/usb/serial/console.c
+++ b/drivers/usb/serial/console.c
@@ -18,6 +18,7 @@
 #include <linux/console.h>
 #include <linux/usb.h>
 #include <linux/usb/serial.h>
+#include "../core/hcd.h"
 
 static int debug;
 
@@ -185,13 +186,38 @@ reset_open_count:
 goto out;
 }
 
+static void usb_do_console_write(struct usb_serial *serial,
+				 struct usb_serial_port *port,
+				 const char *buf, unsigned count)
+{
+	int retval;
+	int loops = 3;
+try_again:
+	/* pass on to the driver specific version of this function if
+	   it is available */
+	if (serial->type->write)
+		retval = serial->type->write(NULL, port, buf, count);
+	else
+		retval = usb_serial_generic_write(NULL, port, buf, count);
+	if (serial->type->max_in_flight_urbs && loops-- &&
+	    retval >= 0 && retval < count) {
+		/* poll the hcd device because the queue is full and
+		 * try this for a total of 3 ms and give up. */
+		count -= retval;
+		buf += retval;
+		mdelay(1);
+		usb_hcd_poll_irq(serial->dev);
+		goto try_again;
+	}
+	dbg("%s - return value : %d", __func__, retval);
+}
+
 static void usb_console_write(struct console *co,
 					const char *buf, unsigned count)
 {
 	static struct usbcons_info *info = &usbcons_info;
 	struct usb_serial_port *port = info->port;
 	struct usb_serial *serial;
-	int retval = -ENODEV;
 
 	if (!port || port->serial->dev->state == USB_STATE_NOTATTACHED)
 		return;
@@ -218,23 +244,11 @@ static void usb_console_write(struct con
 				break;
 			}
 		}
-		/* pass on to the driver specific version of this function if
-		   it is available */
-		if (serial->type->write)
-			retval = serial->type->write(NULL, port, buf, i);
-		else
-			retval = usb_serial_generic_write(NULL, port, buf, i);
-		dbg("%s - return value : %d", __func__, retval);
+		usb_do_console_write(serial, port, buf, i);
 		if (lf) {
 			/* append CR after LF */
 			unsigned char cr = 13;
-			if (serial->type->write)
-				retval = serial->type->write(NULL,
-								port, &cr, 1);
-			else
-				retval = usb_serial_generic_write(NULL,
-								port, &cr, 1);
-			dbg("%s - return value : %d", __func__, retval);
+			usb_do_console_write(serial, port, &cr, 1);
 		}
 		buf += i;
 		count -= i;
--- a/drivers/usb/core/hcd.h
+++ b/drivers/usb/core/hcd.h
@@ -251,6 +251,7 @@ extern void usb_put_hcd(struct usb_hcd *
 extern int usb_add_hcd(struct usb_hcd *hcd,
 		unsigned int irqnum, unsigned long irqflags);
 extern void usb_remove_hcd(struct usb_hcd *hcd);
+extern void usb_hcd_poll_irq(struct usb_device *udev);
 
 struct platform_device;
 extern void usb_hcd_platform_shutdown(struct platform_device *dev);