Staging: quatech_usb2: Improve debug output and fix write_room

This patch contains changes made in the course of successfully reading
data from the device. These consist of a number of corrections and
additions to debug messages, and a fix for incorrect calculation of the
number of characters in the device FIFO which affected the operation of
the write_room method.
The use of semaphores to control access to port settings is replaced by
the preferred use of mutexes as this is the only code that uses them.

Aug 18 17:09:32 [kernel] BUG: unable to handle kernel paging request at f82f122c
Aug 18 17:09:32 [kernel] IP: [<c11e1a63>] tty_port_close_start+0x8c/0x15e
Aug 18 17:09:32 [kernel] *pde = 00000000 
Aug 18 17:09:32 [kernel] Modules linked in: snd_seq snd_seq_device snd_pcm_oss snd_mixer_oss nls_iso8859_1 cifs xt_limit xt_NFLOG nfnetlink_log nfnetlink xt_tcpudp nf_conntrack_ipv4 nf_defrag_ipv4 xt_state nf_conntrack iptable_filter ip_tables x_tables i915 fb drm i2c_algo_bit cfbcopyarea i2c_core video backlight output cfbimgblt cfbfillrect quatech_usb2(C) usbserial uhci_hcd ehci_hcd snd_intel8x0 snd_ac97_codec ac97_bus usbcore tg3 snd_pcm snd_timer libphy snd intel_agp psmouse evdev ohci1394 soundcore ide_cd_mod cdrom ieee1394 snd_page_alloc agpgart floppy
Aug 18 17:09:32 [kernel] Pid: 4192, comm: cat Tainted: G         C (2.6.31-rc6-gkh #9) HP Compaq dc5100 MT(PW097ET)
Aug 18 17:09:32 [kernel] EIP: 0060:[<c11e1a63>] EFLAGS: 00010046 CPU: 0
Aug 18 17:09:32 [kernel] EIP is at tty_port_close_start+0x8c/0x15e
Aug 18 17:09:32 [kernel] EAX: 00000000 EBX: 00000246 ECX: ebacc380 EDX: 00000000
Aug 18 17:09:32 [kernel] ESI: f72f1204 EDI: e6073000 EBP: e60b3ce4 ESP: e60b3ccc
Aug 18 17:09:32 [kernel]  DS: 007b ES: 007b FS: 0000 GS: 00e0 SS: 0068
Aug 18 17:09:32 [kernel]  bcc17886 e60b3d2c bcc17886 f72f1200 f72f1204 e6073000 e60b3d10 f8b01a67
Aug 18 17:09:32 [kernel] <0> 00000000 e60b3d10 c11d9343 e60730a0 ebacc380 bcc17886 e6073000 00000000
Aug 18 17:09:32 [kernel] <0> ebacc380 e60b3d90 c11da71c 00000000 f7802480 bcc17886 ebacc380 00000000
Aug 18 17:09:32 [kernel]  [<f8b01a67>] ? serial_close+0x3c/0x9a [usbserial]
Aug 18 17:09:32 [kernel]  [<c11d9343>] ? tty_fasync+0x63/0xe3
Aug 18 17:09:32 [kernel]  [<c11da71c>] ? tty_release_dev+0x159/0x47d
Aug 18 17:09:32 [kernel]  [<c11804c5>] ? prio_tree_remove+0x6c/0xc5
Aug 18 17:09:32 [kernel]  [<c1081c5f>] ? put_object+0x46/0x5e
Aug 18 17:09:32 [kernel]  [<c11daa59>] ? tty_release+0x19/0x35
Aug 18 17:09:32 [kernel]  [<c1086836>] ? __fput+0xed/0x1e4
Aug 18 17:09:32 [kernel]  [<c1086951>] ? fput+0x24/0x39
Aug 18 17:09:32 [kernel]  [<c108375e>] ? filp_close+0x4c/0x7b
Aug 18 17:09:32 [kernel]  [<c1028076>] ? put_files_struct+0xc3/0xd2
Aug 18 17:09:32 [kernel]  [<c10280b1>] ? exit_files+0x2c/0x40
Aug 18 17:09:32 [kernel]  [<c1028551>] ? do_exit+0xd0/0x5f5
Aug 18 17:09:32 [kernel]  [<c1031751>] ? recalc_sigpending+0x1b/0x4b
Aug 18 17:09:32 [kernel]  [<c1031b8b>] ? dequeue_signal+0x96/0x154
Aug 18 17:09:32 [kernel]  [<c1028ab1>] ? do_group_exit+0x3b/0x77
Aug 18 17:09:32 [kernel]  [<c1032ec3>] ? get_signal_to_deliver+0x140/0x31b
Aug 18 17:09:32 [kernel]  [<c11d90af>] ? tty_put_char+0x43/0x4b
Aug 18 17:09:32 [kernel]  [<c1002633>] ? do_notify_resume+0xae/0x7fb
Aug 18 17:09:32 [kernel]  [<c11dabcd>] ? tty_read+0x8f/0xb5
Aug 18 17:09:32 [kernel]  [<c11dd0be>] ? n_tty_read+0x0/0x5d2
Aug 18 17:09:32 [kernel]  [<c1085560>] ? vfs_read+0xb4/0x178
Aug 18 17:09:32 [kernel]  [<c11dab3e>] ? tty_read+0x0/0xb5
Aug 18 17:09:32 [kernel]  [<c10856e4>] ? sys_read+0x52/0x8b
Aug 18 17:09:32 [kernel]  [<c1002f6a>] ? work_notifysig+0x13/0x19
Aug 18 17:09:32 [kernel] ---[ end trace 16f434ec7e2925bc ]---
Aug 18 17:09:32 [kernel] Fixing recursive fault but reboot is needed!

My guess is that my driver is doing something "wrong" in terms of it's
interface to the higher level layers and so is causing the oops. Are
there any mechanisms to turn on more checking / debugging in the layers
above the usb-serial layer to try and catch the cause of the problem?
I've already got USB_DEBUG enabled, what others might be relevant
(presumably USB_SERIAL_DEBUG isn't)?

Signed-off-by: Richard Ash <richard@audacityteam.org>
Signed-off-by: Greg Kroah-Hartman <gregkh@suse.de>

drivers/staging/quatech_usb2/quatech_usb2.c

@@ -163,7 +163,7 @@ static struct usb_driver quausb2_usb_driver = {
  * each time a write urb is dispatched.
  * - is decremented each time a "transmit empty" message is received
  * by the driver in the data stream.
- * @sem: Semaphore to lock access to this structure when we need to ensure that
+ * @lock: Mutex to lock access to this structure when we need to ensure that
  * races don't occur to access bits of it.
  * @open_count: The number of uses of the port currently having
  * it open, i.e. the reference count.
@@ -177,13 +177,12 @@ struct quatech2_port {
 	bool	rcv_flush;
 	bool	xmit_flush;
 	int	tx_pending_bytes;
-	struct semaphore	sem;
+	struct mutex modelock;
 	int	open_count;
 
 	char	active;		/* someone has this device open */
 	unsigned char		*xfer_to_tty_buffer;
 	wait_queue_head_t	wait;
-
 	__u8	shadowLCR;	/* last LCR value received */
 	__u8	shadowMCR;	/* last MCR value received */
 	char	RxHolding;
@@ -263,11 +262,6 @@ static int qt2_box_flush(struct usb_serial *serial,  unsigned char uart_number,
 		unsigned short rcv_or_xmit);
 static int qt2_boxsetuart(struct usb_serial *serial, unsigned short Uart_Number,
 		unsigned short default_divisor, unsigned char default_LCR);
-/*static int qt2_write(struct tty_struct *tty, struct usb_serial_port *port,
-		      const unsigned char *buf, int count);
-static int qt2_tiocmget(struct tty_struct *tty, struct file *file);
-static int qt2_tiocmset(struct tty_struct *tty, struct file *file,
-			unsigned int set, unsigned int clear);*/
 static int qt2_boxsethw_flowctl(struct usb_serial *serial,
 		unsigned int UartNumber, bool bSet);
 static int qt2_boxsetsw_flowctl(struct usb_serial *serial, __u16 UartNumber,
@@ -356,6 +350,7 @@ static int qt2_attach(struct usb_serial *serial)
 		/* initialise stuff in the structure */
 		qt2_port->open_count = 0;	/* port is not open */
 		spin_lock_init(&qt2_port->lock);
+		mutex_init(&qt2_port->modelock);
 		qt2_set_port_private(port, qt2_port);
 	}
 
@@ -535,7 +530,6 @@ int qt2_open(struct tty_struct *tty, struct usb_serial_port *port)
 	 * Finally we need a bulk in URB to use for background reads from the
 	 * device, which will deal with uplink data from the box to host.
 	 */
-	dbg("serial number is %d", port->serial->minor);
 	dbg("port0 bulk in endpoint is %#.2x", port0->bulk_in_endpointAddress);
 	dbg("port0 bulk out endpoint is %#.2x",
 		port0->bulk_out_endpointAddress);
@@ -700,7 +694,12 @@ static void qt2_close(struct usb_serial_port *port)
 		dev_extra->open_ports);
 }
 
-/* called to deliver writes from the next layer up to the device */
+/**
+ * qt2_write - write bytes from the tty layer out to the USB device.
+ * @buf: The data to be written, size at least count.
+ * @count: The number of bytes requested for transmission.
+ * @return The number of bytes actually accepted for transmission to the device.
+ */
 static int qt2_write(struct tty_struct *tty, struct usb_serial_port *port,
 		const unsigned char *buf, int count)
 {
@@ -708,20 +707,19 @@ static int qt2_write(struct tty_struct *tty, struct usb_serial_port *port,
 	__u8 header_array[5];	/* header used to direct writes to the correct
 	port on the device */
 	struct quatech2_port *port_extra;	/* extra data for this port */
-
 	int result;
 
-	/* get the parent device of the port */
-	serial = port->serial;
+	serial = port->serial; /* get the parent device of the port */
+	port_extra = qt2_get_port_private(port); /* port extra info */
 	if (serial == NULL)
 		return -ENODEV;
-	dbg("%s(): port %d", __func__, port->number);
+	dbg("%s(): port %d, requested to write %d bytes, %d already pending",
+		__func__, port->number, count, port_extra->tx_pending_bytes);
 
 	if (count <= 0)	{
 		dbg("%s(): write request of <= 0 bytes", __func__);
 		return 0;	/* no bytes written */
 	}
-	port_extra = qt2_get_port_private(port);
 
 	/* check if the write urb is already in use, i.e. data already being
 	 * sent to this port */
@@ -747,13 +745,19 @@ static int qt2_write(struct tty_struct *tty, struct usb_serial_port *port,
 	 * the maximum we will ever write to the device as 5 bytes less than
 	 * one URB's worth, by reducing the value of the count argument
 	 * appropriately*/
-	if (count > port->bulk_out_size - QT2_TX_HEADER_LENGTH)
+	if (count > port->bulk_out_size - QT2_TX_HEADER_LENGTH) {
 		count = port->bulk_out_size - QT2_TX_HEADER_LENGTH;
+		dbg("%s(): write request bigger than urb, only accepting "
+			"%d bytes", __func__, count);
+	}
 	/* we must also ensure that the FIFO at the other end can cope with the
 	 * URB we send it, otherwise it will have problems. As above, we can
 	 * restrict the write size by just shrinking count.*/
-	if (count > (QT2_FIFO_DEPTH - port_extra->tx_pending_bytes))
+	if (count > (QT2_FIFO_DEPTH - port_extra->tx_pending_bytes)) {
 		count = QT2_FIFO_DEPTH - port_extra->tx_pending_bytes;
+		dbg("%s(): not enough room in buffer, only accepting %d bytes",
+			__func__, count);
+	}
 	/* now build the header for transmission */
 	header_array[0] = 0x1b;
 	header_array[1] = 0x1b;
@@ -778,17 +782,15 @@ static int qt2_write(struct tty_struct *tty, struct usb_serial_port *port,
 	result = usb_submit_urb(port->write_urb, GFP_ATOMIC);
 	if (result) {
 		/* error couldn't submit urb */
-		result = 0;
+		result = 0;	/* return 0 as nothing got written */
 		dbg("%s(): failed submitting write urb, error %d",
 			__func__, result);
 	} else {
-		port_extra->tx_pending_bytes += (count - QT2_TX_HEADER_LENGTH);
-		/*port->fifo_empty_flag = false;
-		port->xmit_fifo_room_bytes = FIFO_DEPTH -
-		port->xmit_pending_bytes;*/
-		result = count;
-		dbg("%s(): submitted write urb, returning %d",
-			__func__, result);
+		port_extra->tx_pending_bytes += count;
+		result = count;	/* return number of bytes written, i.e. count */
+		dbg("%s(): submitted write urb, wrote %d bytes, "
+			"total pending bytes %d",
+			__func__, result, port_extra->tx_pending_bytes);
 	}
 	return result;
 }
@@ -1178,7 +1180,7 @@ static void qt2_break(struct tty_struct *tty, int break_state)
 	dbg("%s(): port %d, break_value %d", __func__, port->number,
 		break_value);
 
-	down(&port_extra->sem);
+	mutex_lock(&port_extra->modelock);
 	if (!port_extra->open_count) {
 		dbg("%s(): port not open", __func__);
 		goto exit;
@@ -1188,7 +1190,7 @@ static void qt2_break(struct tty_struct *tty, int break_state)
 				QT2_BREAK_CONTROL, 0x40, break_value,
 				port->number, NULL, 0, 300);
 exit:
-	up(&port_extra->sem);
+	mutex_unlock(&port_extra->modelock);
 	dbg("%s(): exit port %d", __func__, port->number);
 
 }
@@ -1209,7 +1211,7 @@ static void qt2_throttle(struct tty_struct *tty)
 		return;
 	}
 
-	down(&port_extra->sem);	/* lock structure */
+	mutex_lock(&port_extra->modelock);	/* lock structure */
 	if (!port_extra->open_count) {
 		dbg("%s(): port not open", __func__);
 		goto exit;
@@ -1224,7 +1226,7 @@ static void qt2_throttle(struct tty_struct *tty)
 
 	port->throttled = 1;
 exit:
-	up(&port_extra->sem);
+	mutex_unlock(&port_extra->modelock);
 	dbg("%s(): port %d: setting port->throttled", __func__, port->number);
 	return;
 }
@@ -1251,7 +1253,7 @@ static void qt2_unthrottle(struct tty_struct *tty)
 	port_extra = qt2_get_port_private(port);
 	port0 = serial->port[0]; /* get the first port's device structure */
 
-	down(&port_extra->sem);
+	mutex_lock(&port_extra->modelock);
 	if (!port_extra->open_count) {
 		dbg("%s(): port %d not open", __func__, port->number);
 		goto exit;
@@ -1275,7 +1277,7 @@ static void qt2_unthrottle(struct tty_struct *tty)
 		}
 	}
 exit:
-	up(&port_extra->sem);
+	mutex_unlock(&port_extra->modelock);
 	dbg("%s(): exit port %d", __func__, port->number);
 	return;
 }
@@ -1442,9 +1444,8 @@ static void qt2_read_bulk_callback(struct urb *urb)
 	bool escapeflag;	/* flag set to true if this loop iteration is
 				 * parsing an escape sequence, rather than
 				 * ordinary data */
-
-
-	dbg("%s(): callback running", __func__);
+	dbg("%s(): callback running, active port is %d", __func__,
+		active->number);
 
 	if (urb->status) {
 		/* read didn't go well */
@@ -1502,7 +1503,7 @@ __func__);
 		/* single port device, input is already stopped, so we don't
 		 * need any more input data */
 		dev_extra->ReadBulkStopped = true;
-			return;
+		return;
 	}
 	/* finally, we are in a situation where we might consider the data
 	 * that is contained within the URB, and what to do about it.
@@ -1512,14 +1513,12 @@ __func__);
 
 	/* active is a usb_serial_port. It has a member port which is a
 	 * tty_port. From this we get a tty_struct pointer which is what we
-	* actually wanted, and keep it on         tty_st */
+	 * actually wanted, and keep it on tty_st */
 	tty_st = tty_port_tty_get(&active->port);
 	if (!tty_st) {
 		dbg("%s - bad tty pointer - exiting", __func__);
 		return;
 	}
-	dbg("%s(): active port %d, tty_st =0x%p\n", __func__, active->number,
-		tty_st);
 	RxCount = urb->actual_length;	/* grab length of data handy */
 
 	if (RxCount) {
@@ -1663,6 +1662,7 @@ __func__);
 		dbg("%s(): failed resubmitting read urb, error %d",
 			__func__, result);
 	} else {
+		dbg("%s() sucessfully resumitted read urb", __func__);
 		if (tty_st && RxCount) {
 			/* if some inbound data was processed, then
 			 * we need to push that through the tty layer
@@ -1675,7 +1675,7 @@ __func__);
 	/* cribbed from serqt_usb2 driver, but not sure which work needs
 	 * scheduling - port0 or currently active port? */
 	/* schedule_work(&port->work); */
-
+	dbg("%s() completed", __func__);
 	return;
 }
 
@@ -1699,7 +1699,9 @@ static void qt2_write_bulk_callback(struct urb *urb)
 			__func__, urb->status);
 		return;
 	}
-
+	/* FIXME What is supposed to be going on here?
+	 * does this actually do anything useful, and should it?
+	 */
 	/*port_softint((void *) serial); commented in vendor driver */
 	schedule_work(&port->work);
 	dbg("%s(): port %d exit", __func__, port->number);