[BUG] usblp_write spins forever after an error

[BUG] usblp_write spins forever after an error

[Andy Lutomirski]

I recently cancelled a print job with the printer's cancel function, and the 
CUPS backend got stuck in usblp_write (using 100% CPU and not responding to 
signals).

The printer is a Kyocera Mita FS-1900 (which has some other problems with the 
linux USB code: usblp_check_status often times out, even though the printer is 
bidirectional -- but that's a whole different issue).

It looks like the problem is that the write failed, so wcomplete got set
to 1 and the status is nonzero.  This case appears to be mishandled in usblp.c:

         while (writecount < count) {
                 if (!usblp->wcomplete) {
			[... not reaching this code]
                 }

                 down (&usblp->sem);
                 if (!usblp->present) {
                         up (&usblp->sem);
                         return -ENODEV;
                 }
                 if (usblp->writeurb->status != 0) {

			[ check status? ]

                         schedule ();
                         continue; <-- problem
                 }

After the write fails, the current code keeps checking the same status, and 
never checks for signals or fails.  I'm not sure what the right fix is, but it 
might be something like this:

--- ./usblp.c.orig      2004-02-15 06:27:29.176169752 -0800
+++ ./usblp.c   2004-02-15 06:29:40.137260640 -0800
@@ -645,13 +645,11 @@
                                 err = usblp->writeurb->status;
                         } else
                                 err = usblp_check_status(usblp, err);
-                       up (&usblp->sem);

-                       /* if the fault was due to disconnect, let khubd's
-                        * call to usblp_disconnect() grab usblp->sem ...
-                        */
-                       schedule ();
-                       continue;
+                       writecount += usblp->writeurb->transfer_buffer_length;
+                       up (&usblp->sem);
+                       count = writecount ? writecount : err;
+                       break;
                 }

                 writecount += usblp->writeurb->transfer_buffer_length;


--Andy

Please CC me -- I'm not subscribed.

Re: [BUG] usblp_write spins forever after an error

[Greg KH]

On Sun, Feb 15, 2004 at 01:55:32PM -0800, Andy Lutomirski wrote:
> I recently cancelled a print job with the printer's cancel function, and 
> the CUPS backend got stuck in usblp_write (using 100% CPU and not 
> responding to signals).

What kernel are you referring to here?

thanks,

greg k-h

Re: [linux-usb-devel] Re: [BUG] usblp_write spins forever after an error

[Paulo Marques]

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

Greg KH wrote:

> On Sun, Feb 15, 2004 at 01:55:32PM -0800, Andy Lutomirski wrote:
> 
>>I recently cancelled a print job with the printer's cancel function, and 
>>the CUPS backend got stuck in usblp_write (using 100% CPU and not 
>>responding to signals).
>>

I wrote a patch some time ago to correct a bug exactly at usblp_write. It is 
still not in the main kernel, but you can give it a try and see if it helps. It 
applies cleanly against 2.6.2-rc2, but I guess it should apply to 2.6.2-rc3.

This patch corrected a problem for me, that happened when a printer presents an 
out-of-paper status while printing a document. The driver would send endless 
garbage to the printer.

I hope this helps,

-- 
Paulo Marques - www.grupopie.com
"In a world without walls and fences who needs windows and gates?"

[-- Attachment #2: usblp_patch --]
[-- Type: text/plain, Size: 1435 bytes --]

--- drivers/usb/class/usblp.c.orig	2004-02-09 14:46:27.000000000 +0000
+++ drivers/usb/class/usblp.c	2004-02-09 15:03:32.281551096 +0000
@@ -603,7 +603,7 @@ static ssize_t usblp_write(struct file *
 {
 	DECLARE_WAITQUEUE(wait, current);
 	struct usblp *usblp = file->private_data;
-	int timeout, err = 0;
+	int timeout, err = 0, transfer_length;
 	size_t writecount = 0;
 
 	while (writecount < count) {
@@ -654,19 +654,13 @@ static ssize_t usblp_write(struct file *
 			continue;
 		}
 
-		writecount += usblp->writeurb->transfer_buffer_length;
-		usblp->writeurb->transfer_buffer_length = 0;
+		transfer_length=(count - writecount);
+		if (transfer_length > USBLP_BUF_SIZE)
+			transfer_length = USBLP_BUF_SIZE;
 
-		if (writecount == count) {
-			up (&usblp->sem);
-			break;
-		}
+		usblp->writeurb->transfer_buffer_length = transfer_length;
 
-		usblp->writeurb->transfer_buffer_length = (count - writecount) < USBLP_BUF_SIZE ?
-							  (count - writecount) : USBLP_BUF_SIZE;
-
-		if (copy_from_user(usblp->writeurb->transfer_buffer, buffer + writecount,
-				usblp->writeurb->transfer_buffer_length)) {
+		if (copy_from_user(usblp->writeurb->transfer_buffer, buffer + writecount, transfer_length)) {
 			up(&usblp->sem);
 			return writecount ? writecount : -EFAULT;
 		}
@@ -683,6 +677,8 @@ static ssize_t usblp_write(struct file *
 			break;
 		}
 		up (&usblp->sem);
+
+		writecount += transfer_length;
 	}
 
 	return count;

Re: [linux-usb-devel] Re: [BUG] usblp_write spins forever after an error

[David Woodhouse]

On Mon, 2004-02-16 at 15:16 +0000, Paulo Marques wrote:
> This patch corrected a problem for me, that happened when a printer presents an 
> out-of-paper status while printing a document. The driver would send endless 
> garbage to the printer.

This patch went in to 2.6.4-rc1, didn't it? It seems to have exacerbated
a problem which used to be occasional, but now seems to happen after
every print job.

I see the following, and the error repeats until I power cycle the
printer (HPLJ 1200 on AMD768 OHCI):

usb 1-1.3.2: control timeout on ep0in
drivers/usb/class/usblp.c: usblp0: error -110 reading printer status



-- 
dwmw2

Re: [linux-usb-devel] Re: [BUG] usblp_write spins forever after an error

[Paulo Marques]

David Woodhouse wrote:

> On Mon, 2004-02-16 at 15:16 +0000, Paulo Marques wrote:
> 
>>This patch corrected a problem for me, that happened when a printer presents an 
>>out-of-paper status while printing a document. The driver would send endless 
>>garbage to the printer.
>>
> 
> This patch went in to 2.6.4-rc1, didn't it? It seems to have exacerbated
> a problem which used to be occasional, but now seems to happen after
> every print job.
> 
> I see the following, and the error repeats until I power cycle the
> printer (HPLJ 1200 on AMD768 OHCI):
> 
> usb 1-1.3.2: control timeout on ep0in
> drivers/usb/class/usblp.c: usblp0: error -110 reading printer status
> 


Yes, unfortunately it did went into 2.6.4-rc1. However it is already corrected 
in 2.6.4-rc2. Luckily it didn't went into any "non-rc" official release.

Please try 2.6.4-rc2, and check to see if the bug went away...

-- 
Paulo Marques - www.grupopie.com
"In a world without walls and fences who needs windows and gates?"

Re: [linux-usb-devel] Re: [BUG] usblp_write spins forever after an error

[David Woodhouse]

On Thu, 2004-03-04 at 12:33 +0000, Paulo Marques wrote:
> Yes, unfortunately it did went into 2.6.4-rc1. However it is already corrected 
> in 2.6.4-rc2. Luckily it didn't went into any "non-rc" official release.
> 
> Please try 2.6.4-rc2, and check to see if the bug went away...

Seems to work; thanks. Does this need backporting to 2.4 too?

-- 
dwmw2

Re: [linux-usb-devel] Re: [BUG] usblp_write spins forever after an error

[Paulo Marques]

David Woodhouse wrote:

> On Thu, 2004-03-04 at 12:33 +0000, Paulo Marques wrote:
> 
>>Yes, unfortunately it did went into 2.6.4-rc1. However it is already corrected 
>>in 2.6.4-rc2. Luckily it didn't went into any "non-rc" official release.
>>
>>Please try 2.6.4-rc2, and check to see if the bug went away...
>>
> 
> Seems to work; thanks. Does this need backporting to 2.4 too?
> 


Unfortunately this isn't over yet.

I got suspicious about this bug fix, because I *did* test my patch before 
submitting it and the kernel that didn't work before, worked fine with my patch.

But now it seems that it is the other way around. After a few digging I found 
out the problem:

The application that I was testing with uses the usblp handle with non-blocking 
I/O .

So my patch does work for non-blocking I/O uses of the port, but wrecks the 
normal blocking mode.

I've already produced a version that works for both cases. I'll just clean it up 
a bit and submit it to 2.4 and 2.6 kernels.

-- 
Paulo Marques - www.grupopie.com
"In a world without walls and fences who needs windows and gates?"

[PATCH] usblp.c (Was: usblp_write spins forever after an error)

[Paulo Marques]

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

Paulo Marques wrote:

> David Woodhouse wrote:
> 
>> On Thu, 2004-03-04 at 12:33 +0000, Paulo Marques wrote:
>>
>>> Yes, unfortunately it did went into 2.6.4-rc1. However it is already 
>>> corrected in 2.6.4-rc2. Luckily it didn't went into any "non-rc" 
>>> official release.
>>>
>>> Please try 2.6.4-rc2, and check to see if the bug went away...
>>>
>>
>> Seems to work; thanks. Does this need backporting to 2.4 too?
>>
> 
> 
> Unfortunately this isn't over yet.
> 
> I got suspicious about this bug fix, because I *did* test my patch 
> before submitting it and the kernel that didn't work before, worked fine 
> with my patch.
> 
> But now it seems that it is the other way around. After a few digging I 
> found out the problem:
> 
> The application that I was testing with uses the usblp handle with 
> non-blocking I/O .
> 
> So my patch does work for non-blocking I/O uses of the port, but wrecks 
> the normal blocking mode.
> 
> I've already produced a version that works for both cases. I'll just 
> clean it up a bit and submit it to 2.4 and 2.6 kernels.


Here it is.

The patch is only one line for 2.6.4-rc2. (I also did a little formatting 
adjustment to better comply with CodingStyle)

For the 2.4.26-pre1 kernel, I also backported the return codes correction patch 
from Oliver Neukum.


The problem with the write function was that, in non-blocking mode, after 
submitting the first urb, the function would return with -EAGAIN, not reporting 
to the application that in fact it had already sent "transfer_length" bytes. 
This way the application would have to send the data *again* causing lots of 
errors.

It did return the correct amount with my first patch, because the writecount was 
being updated on the end of the loop. However this was wrong for blocking I/O.

The "transfer_length" local variable is still needed because if we used the 
transfer_buffer_length field from the urb, then on a second call to write, if 
the urb was still pending (in non-blocking mode), the write would return an 
incorrect amount of data written.

Anyway, this time I tested it using blocking and non-blocking I/O and it works 
for both cases. Even better, this patch only changes the behaviour for 
non-blocking I/O, and keeps the same behaviour for the more usual blocking I/O 
(at least on kernel 2.6).

Please apply,

-- 
Paulo Marques - www.grupopie.com
"In a world without walls and fences who needs windows and gates?"

[-- Attachment #2: usblp_patch_26 --]
[-- Type: text/plain, Size: 916 bytes --]

--- drivers/usb/class/usblp.c.orig	2004-03-05 17:09:00.412189056 +0000
+++ drivers/usb/class/usblp.c	2004-03-05 17:10:30.121551160 +0000
@@ -609,8 +609,10 @@ static ssize_t usblp_write(struct file *
 	while (writecount < count) {
 		if (!usblp->wcomplete) {
 			barrier();
-			if (file->f_flags & O_NONBLOCK)
+			if (file->f_flags & O_NONBLOCK) {
+				writecount += transfer_length;
 				return writecount ? writecount : -EAGAIN;
+			}
 
 			timeout = USBLP_WRITE_TIMEOUT;
 			add_wait_queue(&usblp->wait, &wait);
@@ -670,7 +672,8 @@ static ssize_t usblp_write(struct file *
 
 		usblp->writeurb->transfer_buffer_length = transfer_length;
 
-		if (copy_from_user(usblp->writeurb->transfer_buffer, buffer + writecount, transfer_length)) {
+		if (copy_from_user(usblp->writeurb->transfer_buffer, 
+				   buffer + writecount, transfer_length)) {
 			up(&usblp->sem);
 			return writecount ? writecount : -EFAULT;
 		}

[-- Attachment #3: printer_patch_24 --]
[-- Type: text/plain, Size: 2130 bytes --]

--- drivers/usb/printer.c.orig	2004-03-05 17:29:50.238186624 +0000
+++ drivers/usb/printer.c	2004-03-05 17:35:05.346282912 +0000
@@ -604,14 +604,16 @@ static ssize_t usblp_write(struct file *
 {
 	DECLARE_WAITQUEUE(wait, current);
 	struct usblp *usblp = file->private_data;
-	int timeout, err = 0;
+	int timeout, err = 0, transfer_length = 0;
 	size_t writecount = 0;
 
 	while (writecount < count) {
 		if (!usblp->wcomplete) {
 			barrier();
-			if (file->f_flags & O_NONBLOCK)
-				return -EAGAIN;
+			if (file->f_flags & O_NONBLOCK) {
+				writecount += transfer_length;
+				return writecount ? writecount : -EAGAIN;
+			}
 
 			timeout = USBLP_WRITE_TIMEOUT;
 			add_wait_queue(&usblp->wait, &wait);
@@ -655,27 +657,36 @@ static ssize_t usblp_write(struct file *
 			continue;
 		}
 
-		writecount += usblp->writeurb->transfer_buffer_length;
-		usblp->writeurb->transfer_buffer_length = 0;
-
+		/* We must increment writecount here, and not at the
+		 * end of the loop. Otherwise, the final loop iteration may
+		 * be skipped, leading to incomplete printer output.
+		 */
+		writecount += transfer_length;
 		if (writecount == count) {
 			up (&usblp->sem);
 			break;
 		}
 
-		usblp->writeurb->transfer_buffer_length = (count - writecount) < USBLP_BUF_SIZE ?
-							  (count - writecount) : USBLP_BUF_SIZE;
+		transfer_length = count - writecount;
+		if(transfer_length > USBLP_BUF_SIZE) 
+			transfer_length = USBLP_BUF_SIZE;
+		
+		usblp->writeurb->transfer_buffer_length = transfer_length;
 
-		if (copy_from_user(usblp->writeurb->transfer_buffer, buffer + writecount,
-				usblp->writeurb->transfer_buffer_length)) {
+		if (copy_from_user(usblp->writeurb->transfer_buffer, 
+				   buffer + writecount, transfer_length)) {
 			up(&usblp->sem);
 			return writecount ? writecount : -EFAULT;
 		}
 
 		usblp->writeurb->dev = usblp->dev;
 		usblp->wcomplete = 0;
-		if (usb_submit_urb(usblp->writeurb)) {
-			count = -EIO;
+		err = usb_submit_urb(usblp->writeurb);
+		if (err) {
+			if (err != -ENOMEM)
+				count = -EIO;
+			else
+				count = writecount ? writecount : -ENOMEM;
 			up (&usblp->sem);
 			break;
 		}

Re: [PATCH] usblp.c (Was: usblp_write spins forever after an error)

[Greg KH]

On Fri, Mar 05, 2004 at 06:11:51PM +0000, Paulo Marques wrote:
> 
> Here it is.
> 
> The patch is only one line for 2.6.4-rc2. (I also did a little formatting 
> adjustment to better comply with CodingStyle)
> 
> For the 2.4.26-pre1 kernel, I also backported the return codes correction 
> patch from Oliver Neukum.

Thanks, I've applied this to both the 2.4 and 2.6 usb trees.

greg k-h

Re: [PATCH] usblp.c (Was: usblp_write spins forever after an error)

[David Woodhouse]

On Fri, 2004-03-05 at 18:11 +0000, Paulo Marques wrote:
> Anyway, this time I tested it using blocking and non-blocking I/O and it works 
> for both cases. Even better, this patch only changes the behaviour for 
> non-blocking I/O, and keeps the same behaviour for the more usual blocking I/O 
> (at least on kernel 2.6).

I'm still seeing problems with an HP LaserJet 1200. 

May  7 07:12:56 imladris kernel: usb 1-1.3.2: new full speed USB device using address 10
May  7 07:12:56 imladris kernel: drivers/usb/class/usblp.c: usblp0: USB Bidirectional printer dev 10 if 0 alt 1 proto 2 vid 0x03F0 pid 0x0317
May  8 20:26:12 imladris kernel: drivers/usb/class/usblp.c: usblp0: nonzero read/write bulk status received: -110
May  8 20:26:12 imladris kernel: drivers/usb/class/usblp.c: usblp0: failed reading printer status
May  8 20:26:12 imladris kernel: drivers/usb/class/usblp.c: usblp0: nonzero read/write bulk status received: -110
May  8 20:26:12 imladris kernel: drivers/usb/class/usblp.c: usblp0: error -110 reading printer status
May  8 20:26:43 imladris last message repeated 10225 times
May  8 20:27:09 imladris last message repeated 8780 times

-- 
dwmw2

Re: [BUG] usblp_write spins forever after an error

[Andy Lutomirski]

This was 2.6.1 vanilla.

--Andy

BTW, these aren't going to linux-usb-devel because myrealbox.com fails 
verification.  I emailed them -- hopefully they'll fix it soon.

Greg KH wrote:
> On Sun, Feb 15, 2004 at 01:55:32PM -0800, Andy Lutomirski wrote:
> 
>>I recently cancelled a print job with the printer's cancel function, and 
>>the CUPS backend got stuck in usblp_write (using 100% CPU and not 
>>responding to signals).
> 
> 
> What kernel are you referring to here?
> 
> thanks,
> 
> greg k-h