Discussion:
ftdi_open: error -22
(too old to reply)
Paulo Marques
2004-03-24 16:05:53 UTC
Permalink
Hi,

There is some race condition on the ftdi_sio.c usb serial driver.

I was having problems with an application, so I did the smallest test program
int main(int argc,char *argv[])
{
int handle;
handle=open(argv[1],O_RDWR);
if(handle==-1)
perror("open");
else
close(handle);
return 0;
}
Just running "ftditest /dev/usb/tts/0" acts as expected. It opens and closes the
handle and reports nothing. You can do this several times "by hand" and the
result is the same.

However if you do:

"while true; do ftditest /dev/usb/tts/0; done"
drivers/usb/serial/ftdi_sio.c: ftdi_open - failed submitting read urb, error -22
FTDI FT232BM Compatible ttyUSB0: FTDI FT232BM Compatible converter now
disconnected from ttyUSB0

BTW error -22 is "EINVAL" (Invalid arguments)

I'll try to debug this further, but if anyone as any idea as to why this can
happen I'd be glad to know about it :)

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



-------------------------------------------------------
This SF.Net email is sponsored by: IBM Linux Tutorials
Free Linux tutorial presented by Daniel Robbins, President and CEO of
GenToo technologies. Learn everything from fundamentals to system
administration.http://ads.osdn.com/?ad_id=1470&alloc_id=3638&op=click
_______________________________________________
linux-usb-***@lists.sourceforge.net
To unsubscribe, use the last form field at:
https://lists.sourceforge.net/lists/listinfo/linux-usb-devel
Oliver Neukum
2004-03-24 16:24:58 UTC
Permalink
Post by Paulo Marques
Hi,
There is some race condition on the ftdi_sio.c usb serial driver.
I was having problems with an application, so I did the smallest test program
int main(int argc,char *argv[])
{
int handle;
handle=open(argv[1],O_RDWR);
if(handle==-1)
perror("open");
else
close(handle);
return 0;
}
Just running "ftditest /dev/usb/tts/0" acts as expected. It opens and closes the
handle and reports nothing. You can do this several times "by hand" and the
result is the same.
"while true; do ftditest /dev/usb/tts/0; done"
drivers/usb/serial/ftdi_sio.c: ftdi_open - failed submitting read urb, error -22
FTDI FT232BM Compatible ttyUSB0: FTDI FT232BM Compatible converter now
disconnected from ttyUSB0
BTW error -22 is "EINVAL" (Invalid arguments)
Uhci or Ohci?

Regards
Oliver


-------------------------------------------------------
This SF.Net email is sponsored by: IBM Linux Tutorials
Free Linux tutorial presented by Daniel Robbins, President and CEO of
GenToo technologies. Learn everything from fundamentals to system
administration.http://ads.osdn.com/?ad_id=1470&alloc_id=3638&op=click
_______________________________________________
linux-usb-***@lists.sourceforge.net
To unsubscribe, use the last form field at:
https://lists.sourceforge.net/lists/listinfo/linux-usb-devel
Paulo Marques
2004-03-24 17:19:01 UTC
Permalink
Post by Oliver Neukum
Post by Paulo Marques
Hi,
There is some race condition on the ftdi_sio.c usb serial driver.
I was having problems with an application, so I did the smallest test program
int main(int argc,char *argv[])
{
int handle;
handle=open(argv[1],O_RDWR);
if(handle==-1)
perror("open");
else
close(handle);
return 0;
}
Just running "ftditest /dev/usb/tts/0" acts as expected. It opens and closes the
handle and reports nothing. You can do this several times "by hand" and the
result is the same.
"while true; do ftditest /dev/usb/tts/0; done"
drivers/usb/serial/ftdi_sio.c: ftdi_open - failed submitting read urb, error -22
FTDI FT232BM Compatible ttyUSB0: FTDI FT232BM Compatible converter now
disconnected from ttyUSB0
BTW error -22 is "EINVAL" (Invalid arguments)
Uhci or Ohci?
Sorry about the lack of details...

It is a Intel UHCI controller. The machine is a Celeron 1.2GHz.

Kernel is 2.6.5-rc2 with your patch to fix the DMA on stack problem.

I have delayed this response to have a little more debugging info to give.

My first report was actually incorrect, because the test case I presented only
works *after* the application that caused the problem in the first place has ran.

After that, even if I unplug/replug the converter I get the same problem with
the above test case.

I compiled the kernel with USB_DEBUG and USB_SERIAL_DEBUG.

Here is the part of the system log I believe is relevant (this snippet starts
when the application is still holding the port open):

drivers/usb/serial/ftdi_sio.c: ftdi_read_bulk_callback
drivers/usb/serial/ftdi_sio.c: Status only: 001o 140o
drivers/usb/serial/ftdi_sio.c: ftdi_read_bulk_callback
drivers/usb/serial/ftdi_sio.c: Status only: 001o 140o
drivers/usb/serial/ftdi_sio.c: ftdi_read_bulk_callback
drivers/usb/serial/ftdi_sio.c: ftdi_read_bulk_callback - length = 16, data = 01
60 c4 12 cb 4e 37 e6 80 ab 6f 1a 58 ae 8e e5
drivers/usb/serial/ftdi_sio.c: ftdi_read_bulk_callback
drivers/usb/serial/ftdi_sio.c: ftdi_read_bulk_callback - length = 8, data = 01
60 b7 14 2b 00 82 59
drivers/usb/serial/usb-serial.c: serial_close - port 0
drivers/usb/serial/ftdi_sio.c: ftdi_close
drivers/usb/serial/ftdi_sio.c: ftdi_read_bulk_callback
drivers/usb/serial/usb-serial.c: serial_open
drivers/usb/serial/ftdi_sio.c: ftdi_open
drivers/usb/serial/ftdi_sio.c: ftdi_set_termios
drivers/usb/serial/ftdi_sio.c: Setting CS8
drivers/usb/serial/ftdi_sio.c: get_ftdi_divisor - tty_get_baud_rate reports
speed 9600
drivers/usb/serial/ftdi_sio.c: get_ftdi_divisor - Baud rate set to 9600 (divisor
0x4138) on chip FT232BM
drivers/usb/serial/ftdi_sio.c: ftdi_set_termios Turning off hardware flow control
drivers/usb/serial/usb-serial.c: serial_close - port 0
drivers/usb/serial/ftdi_sio.c: ftdi_close
drivers/usb/serial/usb-serial.c: serial_open
drivers/usb/serial/ftdi_sio.c: ftdi_open
drivers/usb/serial/ftdi_sio.c: ftdi_set_termios
drivers/usb/serial/ftdi_sio.c: Setting CS8
drivers/usb/serial/ftdi_sio.c: get_ftdi_divisor - tty_get_baud_rate reports
speed 9600
drivers/usb/serial/ftdi_sio.c: get_ftdi_divisor - Baud rate set to 9600 (divisor
0x4138) on chip FT232BM
drivers/usb/serial/ftdi_sio.c: ftdi_set_termios Turning off hardware flow control
drivers/usb/serial/ftdi_sio.c: ftdi_open - failed submitting read urb, error -22
drivers/usb/serial/usb-serial.c: serial_close - port 0
drivers/usb/serial/ftdi_sio.c: ftdi_close
drivers/usb/serial/usb-serial.c: destroy_serial - FTDI FT232BM Compatible
drivers/usb/serial/usb-serial.c: serial_shutdown
drivers/usb/serial/ftdi_sio.c: ftdi_shutdown
drivers/usb/serial/usb-serial.c: return_serial
drivers/usb/serial/ftdi_sio.c: ftdi_read_bulk_callback
FTDI FT232BM Compatible ttyUSB0: FTDI FT232BM Compatible converter now
disconnected from ttyUSB0
drivers/usb/serial/usb-serial.c: port_release - ttyUSB0

I can send a full log if you think it is necessary.

One thing that caught my attention was the "ftdi_read_bulk_callback" *after* the
first "ftdi_close".

I'll continue the bug hunt. If you have any suggestions, please let me know.

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



-------------------------------------------------------
This SF.Net email is sponsored by: IBM Linux Tutorials
Free Linux tutorial presented by Daniel Robbins, President and CEO of
GenToo technologies. Learn everything from fundamentals to system
administration.http://ads.osdn.com/?ad_id=1470&alloc_id=3638&op=click
_______________________________________________
linux-usb-***@lists.sourceforge.net
To unsubscribe, use the last form field at:
https://lists.sourceforge.net/lists/listinfo/linux-usb-devel
Oliver Neukum
2004-03-24 18:00:29 UTC
Permalink
Post by Paulo Marques
One thing that caught my attention was the "ftdi_read_bulk_callback" *after* the
first "ftdi_close".
I'll continue the bug hunt. If you have any suggestions, please let me know.
It is normal that there is at least one call to the completion handler
after close, because close unlinks the read URB which causes the
completion handler to run.
There _not_ being a call to the completion handler is odd.

Please go to drivers/usb/core/urb.c and add a debugging printk
to any place where -EINVAL is returned.

Regards
Oliver


-------------------------------------------------------
This SF.Net email is sponsored by: IBM Linux Tutorials
Free Linux tutorial presented by Daniel Robbins, President and CEO of
GenToo technologies. Learn everything from fundamentals to system
administration.http://ads.osdn.com/?ad_id=1470&alloc_id=3638&op=click
_______________________________________________
linux-usb-***@lists.sourceforge.net
To unsubscribe, use the last form field at:
https://lists.sourceforge.net/lists/listinfo/linux-usb-devel
Paulo Marques
2004-03-24 18:52:48 UTC
Permalink
Post by Oliver Neukum
Post by Paulo Marques
One thing that caught my attention was the "ftdi_read_bulk_callback" *after* the
first "ftdi_close".
I'll continue the bug hunt. If you have any suggestions, please let me know.
It is normal that there is at least one call to the completion handler
after close, because close unlinks the read URB which causes the
completion handler to run.
There _not_ being a call to the completion handler is odd.
Please go to drivers/usb/core/urb.c and add a debugging printk
to any place where -EINVAL is returned.
Ok, done.

The EINVAL is being returned from the usb_submit_urb in urb.c because
urb->hcpriv is not NULL.
--
Paulo Marques - www.grupopie.com
"In a world without walls and fences who needs windows and gates?"



-------------------------------------------------------
This SF.Net email is sponsored by: IBM Linux Tutorials
Free Linux tutorial presented by Daniel Robbins, President and CEO of
GenToo technologies. Learn everything from fundamentals to system
administration.http://ads.osdn.com/?ad_id=1470&alloc_id=3638&op=click
_______________________________________________
linux-usb-***@lists.sourceforge.net
To unsubscribe, use the last form field at:
https://lists.sourceforge.net/lists/listinfo/linux-usb-devel
Oliver Neukum
2004-03-24 19:37:06 UTC
Permalink
Post by Paulo Marques
Post by Oliver Neukum
Post by Paulo Marques
One thing that caught my attention was the "ftdi_read_bulk_callback" *after* the
first "ftdi_close".
I'll continue the bug hunt. If you have any suggestions, please let me know.
It is normal that there is at least one call to the completion handler
after close, because close unlinks the read URB which causes the
completion handler to run.
There _not_ being a call to the completion handler is odd.
Please go to drivers/usb/core/urb.c and add a debugging printk
to any place where -EINVAL is returned.
Ok, done.
The EINVAL is being returned from the usb_submit_urb in urb.c because
urb->hcpriv is not NULL.
OK. This means that the URB is not unlinked.
Possibly unlinking in close() is failing.
Could you go to static void ftdi_close() and add a debugging printk
for the result of usb_unlink_urb() there.
There is a race you might trigger, I don't understand how you do it
consistently.

Regards
Oliver


-------------------------------------------------------
This SF.Net email is sponsored by: IBM Linux Tutorials
Free Linux tutorial presented by Daniel Robbins, President and CEO of
GenToo technologies. Learn everything from fundamentals to system
administration.http://ads.osdn.com/?ad_id=1470&alloc_id=3638&op=click
_______________________________________________
linux-usb-***@lists.sourceforge.net
To unsubscribe, use the last form field at:
https://lists.sourceforge.net/lists/listinfo/linux-usb-devel
Paulo Marques
2004-03-24 20:13:39 UTC
Permalink
Post by Oliver Neukum
Post by Paulo Marques
Ok, done.
The EINVAL is being returned from the usb_submit_urb in urb.c because
urb->hcpriv is not NULL.
OK. This means that the URB is not unlinked.
Possibly unlinking in close() is failing.
Could you go to static void ftdi_close() and add a debugging printk
for the result of usb_unlink_urb() there.
There is a race you might trigger, I don't understand how you do it
consistently.
After a few more debug steps I found the problem... (at least I think I do :)

The application was clearing the HUPCL flag in termios->c_cflag.

In "ftdi_close" the read_urb unlinking is in the "if (c_cflag & HUPCL){"
construct that should be only used to set the rts/dtr pins.

There is still a comment there "/* unlink the running write urbs */" that has no
code whatsoever. Did someone remove the code for some reason and forgot to
remove the comment? (or was the comment written before the code and the code
never showed up :)

Anyway, the patch below fixes it for me.

Thanks for all the help
--
Paulo Marques - www.grupopie.com
"In a world without walls and fences who needs windows and gates?"
Paulo Marques
2004-03-24 20:51:06 UTC
Permalink
Post by Paulo Marques
Post by Oliver Neukum
Post by Paulo Marques
Ok, done.
The EINVAL is being returned from the usb_submit_urb in urb.c because
urb->hcpriv is not NULL.
OK. This means that the URB is not unlinked.
Possibly unlinking in close() is failing.
Could you go to static void ftdi_close() and add a debugging printk
for the result of usb_unlink_urb() there.
There is a race you might trigger, I don't understand how you do it
consistently.
After a few more debug steps I found the problem... (at least I think I do :)
The application was clearing the HUPCL flag in termios->c_cflag.
In "ftdi_close" the read_urb unlinking is in the "if (c_cflag & HUPCL){"
construct that should be only used to set the rts/dtr pins.
There is still a comment there "/* unlink the running write urbs */"
that has no code whatsoever. Did someone remove the code for some reason
and forgot to remove the comment? (or was the comment written before the
code and the code never showed up :)
Anyway, the patch below fixes it for me.
I really hate replying to myself, but the patch has a bug. The correct patch is
attached.

Sorry about this :(
--
Paulo Marques - www.grupopie.com
"In a world without walls and fences who needs windows and gates?"
Pete Zaitcev
2004-03-24 18:01:39 UTC
Permalink
On Wed, 24 Mar 2004 16:05:53 +0000
Post by Paulo Marques
"while true; do ftditest /dev/usb/tts/0; done"
drivers/usb/serial/ftdi_sio.c: ftdi_open - failed submitting read urb, error -22
FTDI FT232BM Compatible ttyUSB0: FTDI FT232BM Compatible converter now
disconnected from ttyUSB0
BTW error -22 is "EINVAL" (Invalid arguments)
I think I saw a similar thing on 2.4. I'll recheck.

-- Pete


-------------------------------------------------------
This SF.Net email is sponsored by: IBM Linux Tutorials
Free Linux tutorial presented by Daniel Robbins, President and CEO of
GenToo technologies. Learn everything from fundamentals to system
administration.http://ads.osdn.com/?ad_id=1470&alloc_id=3638&op=click
_______________________________________________
linux-usb-***@lists.sourceforge.net
To unsubscribe, use the last form field at:
https://lists.sourceforge.net/lists/listinfo/linux-usb-devel
Loading...