Following on from my report in the thread "Gadgetfs: how to ack a
control out?":
At the host end I have 2.6.19 on VIA hardware and a recently-downloaded
testusb.c (it doesn't seem to have a version number).
At the device end I have 2.6.19 plus 3 patches: as823.patch, which
fixes net2280 to NAK rather than send ZLPs when it does not yet have
data for a control IN message, and two patches to gadgetfs posted by
Milan Svoboda on 2006-12-15 to fix an error-handling path. I have a
Net2280 PCI card.
Test 0-9 and 11-13 pass. Test 14 fails:
# strace ./testusb -D /proc/bus/usb/004/010 -t14 -c 15000 -s 256 -v 1
..
open("/proc/bus/usb/004/010", O_RDWR) = 4
ioctl(4, USBDEVFS_IOCTL, 0xbf8df42c) = -1 EOPNOTSUPP (Operation not
supported)
I thought this had worked before, but maybe I am getting confused with
my g_zero testing; I believe it's not expected to work with gadgetfs
and usb.c, is this right?
Anyway the current issue is test 10, which fails more often than not.
Perhaps it passes one time in three. I have tried to spot a pattern;
maybe it is more likely to work when usb.c is first started, more more
likely to fail later. It has certainly been known to fail on the first
run though. Here are the symptoms when it fails. [Note that the
output below is not all from the same run.]
# ./testusb -D /proc/bus/usb/004/010 -t10
(Never completes, no output)
dmesg:
Jan 8 12:37:38 egypt kernel: usbtest 4-4:3.0: TEST 10: queue 32
control calls, 1000 times
(no further output)
strace:
open("/proc/bus/usb/004/010", O_RDWR) = 4
ioctl(4, USBDEVFS_IOCTL
(stops at that point)
Here's some usbmon output, up to the point where it stops:
c78488c0 33909618 S Ci:024:00 s 80 06 0400 0000 0009 9 <
c7848860 33909860 C Co:024:00 0 0
c7848860 33909862 S Co:024:00 s 02 01 0000 0000 0000 0
c7848800 33909868 C Ci:024:00 0 2 = 0000
c7848800 33909869 S Ci:024:00 s 82 00 0000 0000 0002 2 <
c78487a0 33909875 C Ci:024:00 -121 39 = 09022700 010304c0 01090400
0003ff00 0005
0705 87020002 00070503 02000201
c78487a0 33909876 S Ci:024:00 s 80 06 0200 0000 0400 1024 <
c7848740 33909985 C Ci:024:00 -32 0
c7848740 33909986 S Ci:024:00 s 80 06 0500 0000 0009 9 <
c78486e0 33910237 C Ci:024:00 -121 4 = 04030904
c78486e0 33910240 S Ci:024:00 s 80 06 0300 0000 0009 9 <
c7848680 33910360 C Ci:024:00 -121 39 = 09022700 010304c0 01090400
0003ff00 0005
0705 87020002 00070503 02000201
c7848680 33910362 S Ci:024:00 s 80 06 0200 0000 03c0 960 <
c7848620 33910367 C Ci:024:00 -121 18 = 12010002 ff000040 2505a4a4
00010102 0301
c7848620 33910369 S Ci:024:00 s 80 06 0100 0000 0040 64 <
c78485c0 33910485 C Ci:024:00 0 18 = 12010002 ff000040 2505a4a4
00010102 0301
c78485c0 33910487 S Ci:024:00 s 80 06 0100 0000 0012 18 <
c78482c0 33910493 C Ci:024:00 0 9 = 09022700 010304c0 01
c78482c0 33910494 S Ci:024:00 s 80 06 0200 0000 0009 9 <
c7848320 33910609 C Ci:024:00 0 1 = 00
c7848320 33910611 S Ci:024:00 s 81 0a 0000 0000 0001 1 <
c7848f80 33910735 C Ci:024:00 0 2 = 0000
c7848f80 33910737 S Ci:024:00 s 81 00 0000 0000 0002 2 <
c78483e0 33910744 C Ci:024:00 0 2 = 0100
c78483e0 33910745 S Ci:024:00 s 80 00 0000 0000 0002 2 <
c7848440 33910751 C Ci:024:00 0 10 = 0a060002 ff000040 0100
c7848440 33910752 S Ci:024:00 s 80 06 0600 0000 000a 10 <
c78484a0 33910859 C Ci:024:00 0 18 = 09022700 010304c0 01090400
0003ff00 0005
c78484a0 33910861 S Ci:024:00 s 80 06 0200 0000 0012 18 <
c7848500 33910868 C Ci:024:00 -32 0
c7848500 33910869 S Ci:024:00 s 80 06 0400 0000 0009 9 <
c7848260 33911110 C Co:024:00 0 0
c7848260 33911112 S Co:024:00 s 02 01 0000 0000 0000 0
c7848380 33911117 C Ci:024:00 0 2 = 0000
c7848380 33911118 S Ci:024:00 s 82 00 0000 0000 0002 2 <
c7848560 33911124 C Ci:024:00 -121 39 = 09022700 010304c0 01090400
0003ff00 0005
0705 87020002 00070503 02000201
c7848560 33911125 S Ci:024:00 s 80 06 0200 0000 0400 1024 <
c78481a0 33911235 C Ci:024:00 -32 0
c78481a0 33911236 S Ci:024:00 s 80 06 0500 0000 0009 9 <
On the device end, usb -v output is:
/dev/gadget/net2280 ep0 configured
serial="13hz78wkvlc3179o5r9bj6rbm28wotubury5m1jhsqxas9xbceylqit6yvj0tqx"
CONNECT high speed
DISCONNECT
read 2 ep0 events
CONNECT high speed
SETUP 80.06 v0300 i0000 255
SETUP 80.06 v0302 i0409 255
SETUP 80.06 v0301 i0409 255
SETUP 80.06 v0303 i0409 255
SETUP 00.09 v0003 i0000 0
CONFIG #3
simple_source_thread start -1209627728 fd 4
simple_sink_thread start -1218020432 fd 5
SETUP 80.06 v0304 i0409 255
SETUP 80.06 v0305 i0409 255
Then these two lines are repeated:
SETUP 81.0a v0000 i0000 1
SETUP 80.06 v0300 i0000 9
In one failing case the lines were output 1312 times, in another case
1495 times, then no further output. In another case they were output
only once. When the test passes they are output 2000 times. Normally
the last line to be output is the 80.06 line, but I have seen a case
where it was the other one.
I have tried strace -f on usb.c and its output finishes like this:
[pid 2177] open("ep-a", O_RDWR <unfinished ...>
[pid 2178] open("ep-b", O_RDWR <unfinished ...>
[pid 2177] <... open resumed> ) = 4
[pid 2178] <... open resumed> ) = 5
[pid 2177] write(4, "[EMAIL PROTECTED]", 18
<unfinished ...>
[pid 2178] write(5, "[EMAIL PROTECTED]", 18
<unfinished ...>
[pid 2177] <... write resumed> ) = 18
[pid 2178] <... write resumed> ) = 18
[pid 2177] write(4,
"\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 7168
<unfinished ...>
[pid 2178] read(5, <unfinished ...>
[pid 2176] <... sched_yield resumed> ) = 0
[pid 2176] rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
[pid 2176] read(3, "", 0) = 0
[pid 2176] --- SIGIO (I/O possible) @ 0 (0) ---
[pid 2176] rt_sigreturn(0x3) = 0
[pid 2176] rt_sigtimedwait(~[RTMIN RT_1], 0, 0, 8) = 29
[pid 2176] read(3, "\3\0\0\0\200\6\4\3\t\4\2\0", 60) = 12
[pid 2176] write(3, "$\3", 2) = 2
[pid 2176] --- SIGIO (I/O possible) @ 0 (0) ---
[pid 2176] rt_sigreturn(0x3) = 2
[pid 2176] rt_sigtimedwait(~[RTMIN RT_1], 0, 0, 8) = 29
[pid 2176] read(3, "\3\0\0\0\200\6\5\3\t\4\377\0", 60) = 12
[pid 2176] write(3, "\30\3S\0o\0u\0r\0c\0e\0/\0S\0i\0n\0k\0", 24) = 24
[pid 2176] rt_sigtimedwait(~[RTMIN RT_1], 0, 0, 8) = 29
[pid 2176] read(3, "\3\0\0\0\201\n\0\0\0\0\1\0", 60) = 12
[pid 2176] write(3, "\0", 1) = 1
[pid 2176] --- SIGIO (I/O possible) @ 0 (0) ---
[pid 2176] rt_sigreturn(0x3) = 1
[pid 2176] rt_sigtimedwait(~[RTMIN RT_1], <unfinished ...>
So the ep-a thread (2177) is in a write, the ep-b thread (2178) is in a
read, and the main program (2176) is waiting for a signal. However,
I'm not convinced that this is doing the same as without strace; it
doesn't seem to have done very much since starting, and dmesg on the
host has various "khudb timed out" messages amongst the enumeration information.
I have also tessted with as823.patch reverted. In this case I get:
# ./testusb -D /proc/bus/usb/004/032 -t10
unknown speed /proc/bus/usb/004/032
/proc/bus/usb/004/032 test 10 --> 121 (error 121)
Is this expected?
Let me know what else I can do.
Cheers,
Phil.
-------------------------------------------------------------------------
Take Surveys. Earn Cash. Influence the Future of IT
Join SourceForge.net's Techsay panel and you'll get the chance to share your
opinions on IT & business topics through brief surveys - and earn cash
http://www.techsay.com/default.php?page=join.php&p=sourceforge&CID=DEVDEV
_______________________________________________
linux-usb-devel@lists.sourceforge.net
To unsubscribe, use the last form field at:
https://lists.sourceforge.net/lists/listinfo/linux-usb-devel
