usb/140810: 8.X+ uftdi copy and paste problem / tty overflow

Corey Smith csmith at bonddesk.com
Mon Nov 23 19:16:18 UTC 2009 

On Mon, 2009-11-23 at 11:25 -0500, Hans Petter Selasky wrote:
> sysctl hw.usb.ucom.debug=15

Thanks for the quick reply.  I decided to do a fresh install of
8.0-RELEASE amd64 before I re-ran the test.  Here are the details:

# uname -a
FreeBSD lab1 8.0-RELEASE FreeBSD 8.0-RELEASE #0: Sat Nov 21 15:02:08 UTC 2009     root at mason.cse.buffalo.edu:/usr/obj/usr/src/sys/GENERIC  amd64
# sysctl hw.usb.ucom.debug=15
# tip ucom1
connected
# paste 160 "a"s followed by a newline (may take several attempts when debugging is enabled)
aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa

Nov 23 14:54:13 lab1 su: csmith to root on /dev/pts/0
Nov 23 14:57:14 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:14 lab1 kernel: ucom_get_data:1064: cnt=1
Nov 23 14:57:14 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:14 lab1 kernel: ucom_get_data:1064: cnt=1
Nov 23 14:57:14 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:14 lab1 kernel: ucom_get_data:1064: cnt=1
Nov 23 14:57:14 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:14 lab1 kernel: ucom_get_data:1064: cnt=1
Nov 23 14:57:14 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:14 lab1 kernel: ucom_get_data:1064: cnt=1
Nov 23 14:57:14 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:14 lab1 kernel: ucom_get_data:1064: cnt=1
Nov 23 14:57:14 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:14 lab1 kernel: ucom_get_data:1064: cnt=1
Nov 23 14:57:14 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:14 lab1 kernel: ucom_get_data:1064: cnt=1
Nov 23 14:57:14 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:14 lab1 kernel: ucom_get_data:1064: cnt=1
Nov 23 14:57:14 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:14 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:14 lab1 kernel: ucom_get_data:1064: cnt=2
Nov 23 14:57:14 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:14 lab1 last message repeated 2 times
Nov 23 14:57:14 lab1 kernel: ucom_get_data:1064: cnt=3
Nov 23 14:57:14 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:14 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:14 lab1 kernel: ucom_get_data:1064: cnt=2
Nov 23 14:57:14 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:14 lab1 last message repeated 4 times
Nov 23 14:57:14 lab1 kernel: ucom_get_data:1064: cnt=5
Nov 23 14:57:14 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:14 lab1 last message repeated 8 times
Nov 23 14:57:14 lab1 kernel: ucom_get_data:1064: cnt=9
Nov 23 14:57:14 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:14 lab1 last message repeated 4 times
Nov 23 14:57:14 lab1 kernel: ucom_get_data:1064: cnt=5
Nov 23 14:57:14 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:14 lab1 last message repeated 13 times
Nov 23 14:57:14 lab1 kernel: ucom_get_data:1064: cnt=13
Nov 23 14:57:14 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:14 lab1 last message repeated 26 times
Nov 23 14:57:14 lab1 kernel: ucom_get_data:1064: cnt=27
Nov 23 14:57:14 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:14 lab1 last message repeated 14 times
Nov 23 14:57:14 lab1 kernel: ucom_get_data:1064: cnt=15
Nov 23 14:57:14 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:14 lab1 last message repeated 37 times
Nov 23 14:57:14 lab1 kernel: ucom_get_data:1064: cnt=37
Nov 23 14:57:14 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:14 lab1 last message repeated 34 times
Nov 23 14:57:14 lab1 kernel: ucom_get_data:1064: cnt=33
Nov 23 14:57:14 lab1 kernel: ucom_get_data:1064: cnt=0
Nov 23 14:57:15 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:15 lab1 kernel: ucom_get_data:1064: cnt=1
Nov 23 14:57:15 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:15 lab1 kernel: ucom_get_data:1064: cnt=1
Nov 23 14:57:15 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:15 lab1 kernel: ucom_get_data:1064: cnt=1
Nov 23 14:57:15 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:15 lab1 kernel: ucom_get_data:1064: cnt=1
Nov 23 14:57:15 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:15 lab1 kernel: ucom_get_data:1064: cnt=1
Nov 23 14:57:15 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:15 lab1 kernel: ucom_get_data:1064: cnt=1
Nov 23 14:57:15 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:15 lab1 kernel: ucom_get_data:1064: cnt=1
Nov 23 14:57:15 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:15 lab1 kernel: ucom_get_data:1064: cnt=1
Nov 23 14:57:15 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:15 lab1 kernel: ucom_get_data:1064: cnt=1
Nov 23 14:57:15 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:15 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:15 lab1 kernel: ucom_get_data:1064: cnt=2
Nov 23 14:57:15 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:15 lab1 last message repeated 2 times
Nov 23 14:57:15 lab1 kernel: ucom_get_data:1064: cnt=3
Nov 23 14:57:15 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:15 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:15 lab1 kernel: ucom_get_data:1064: cnt=2
Nov 23 14:57:15 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:15 lab1 last message repeated 4 times
Nov 23 14:57:15 lab1 kernel: ucom_get_data:1064: cnt=5
Nov 23 14:57:15 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:15 lab1 last message repeated 8 times
Nov 23 14:57:15 lab1 kernel: ucom_get_data:1064: cnt=9
Nov 23 14:57:15 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:15 lab1 last message repeated 4 times
Nov 23 14:57:15 lab1 kernel: ucom_get_data:1064: cnt=5
Nov 23 14:57:15 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:15 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:15 lab1 kernel: 
Nov 23 14:57:15 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:15 lab1 last message repeated 3 times
Nov 23 14:57:15 lab1 kernel: 
Nov 23 14:57:15 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:15 lab1 kernel: 
Nov 23 14:57:15 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:15 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:15 lab1 kernel: 
Nov 23 14:57:15 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:15 lab1 kernel: 
Nov 23 14:57:15 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:15 lab1 last message repeated 3 times
Nov 23 14:57:15 lab1 kernel: ucom_get_data:1064: cnt=14
Nov 23 14:57:15 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:15 lab1 last message repeated 14 times
Nov 23 14:57:15 lab1 kernel: 
Nov 23 14:57:15 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:15 lab1 last message repeated 9 times
Nov 23 14:57:15 lab1 kernel: 
Nov 23 14:57:15 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:15 lab1 kernel: 
Nov 23 14:57:15 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:15 lab1 kernel: ucom_get_data:1064: cnt=26
Nov 23 14:57:15 lab1 kernel: 
Nov 23 14:57:15 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:15 lab1 last message repeated 14 times
Nov 23 14:57:15 lab1 kernel: ucom_get_data:1064: cnt=15
Nov 23 14:57:15 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:15 lab1 last message repeated 11 times
Nov 23 14:57:15 lab1 kernel: 
Nov 23 14:57:15 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:15 lab1 last message repeated 5 times
Nov 23 14:57:15 lab1 kernel: 
Nov 23 14:57:15 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:15 lab1 kernel: 
Nov 23 14:57:15 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:15 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:15 lab1 kernel: 
Nov 23 14:57:15 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:15 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:15 lab1 kernel: 
Nov 23 14:57:15 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:15 lab1 last message repeated 12 times
Nov 23 14:57:15 lab1 kernel: 
Nov 23 14:57:15 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:15 lab1 last message repeated 5 times
Nov 23 14:57:15 lab1 kernel: ucom_get_data:1064: cnt=41
Nov 23 14:57:15 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:15 lab1 last message repeated 17 times
Nov 23 14:57:15 lab1 kernel: 
Nov 23 14:57:15 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:15 lab1 last message repeated 12 times
Nov 23 14:57:15 lab1 kernel: ucom_get_data:1064: cnt=29
Nov 23 14:57:15 lab1 kernel: ucom_get_data:1064: cnt=0
Nov 23 14:57:16 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:16 lab1 kernel: ucom_get_data:1064: cnt=1
Nov 23 14:57:16 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:16 lab1 kernel: ucom_get_data:1064: cnt=1
Nov 23 14:57:16 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:16 lab1 kernel: ucom_get_data:1064: cnt=1
Nov 23 14:57:16 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:16 lab1 kernel: ucom_get_data:1064: cnt=1
Nov 23 14:57:16 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:16 lab1 kernel: ucom_get_data:1064: cnt=1
Nov 23 14:57:16 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:16 lab1 kernel: ucom_get_data:1064: cnt=1
Nov 23 14:57:16 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:16 lab1 kernel: ucom_get_data:1064: cnt=1
Nov 23 14:57:16 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:16 lab1 kernel: ucom_get_data:1064: cnt=1
Nov 23 14:57:16 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:16 lab1 kernel: ucom_get_data:1064: cnt=1
Nov 23 14:57:16 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:16 lab1 last message repeated 2 times
Nov 23 14:57:16 lab1 kernel: ucom_get_data:1064: cnt=3
Nov 23 14:57:16 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:16 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:16 lab1 kernel: ucom_get_data:1064: cnt=2
Nov 23 14:57:16 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:16 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:16 lab1 kernel: ucom_get_data:1064: cnt=2
Nov 23 14:57:16 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:16 lab1 last message repeated 7 times
Nov 23 14:57:16 lab1 kernel: ucom_get_data:1064: cnt=8
Nov 23 14:57:16 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:16 lab1 last message repeated 5 times
Nov 23 14:57:16 lab1 kernel: ucom_get_data:1064: cnt=6
Nov 23 14:57:16 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:16 lab1 last message repeated 4 times
Nov 23 14:57:16 lab1 kernel: ucom_get_data:1064: cnt=5
Nov 23 14:57:16 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:16 lab1 last message repeated 23 times
Nov 23 14:57:16 lab1 kernel: ucom_get_data:1064: cnt=23
Nov 23 14:57:16 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:16 lab1 last message repeated 16 times
Nov 23 14:57:16 lab1 kernel: ucom_get_data:1064: cnt=17
Nov 23 14:57:16 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:16 lab1 last message repeated 14 times
Nov 23 14:57:16 lab1 kernel: ucom_get_data:1064: cnt=15
Nov 23 14:57:16 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:16 lab1 last message repeated 68 times
Nov 23 14:57:16 lab1 kernel: ucom_get_data:1064: cnt=64
Nov 23 14:57:16 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:16 lab1 last message repeated 4 times
Nov 23 14:57:16 lab1 kernel: ucom_get_data:1064: cnt=6
Nov 23 14:57:16 lab1 kernel: ucom_get_data:1064: cnt=0
Nov 23 14:57:18 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:18 lab1 kernel: ucom_get_data:1064: cnt=1
Nov 23 14:57:18 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:18 lab1 last message repeated 135 times
Nov 23 14:57:18 lab1 kernel: 
Nov 23 14:57:18 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:18 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:18 lab1 kernel: 
Nov 23 14:57:18 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:18 lab1 last message repeated 9 times
Nov 23 14:57:18 lab1 kernel: 
Nov 23 14:57:18 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:18 lab1 kernel: 
Nov 23 14:57:18 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:18 lab1 kernel: 
Nov 23 14:57:18 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:18 lab1 last message repeated 3 times
Nov 23 14:57:18 lab1 kernel: 
Nov 23 14:57:18 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:18 lab1 kernel: 
Nov 23 14:57:18 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:18 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:18 lab1 kernel: 
Nov 23 14:57:18 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:18 lab1 kernel: 
Nov 23 14:57:18 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:39 lab1 last message repeated 1307 times
Nov 23 14:57:39 lab1 kernel: 
Nov 23 14:57:39 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:42 lab1 last message repeated 212 times
Nov 23 14:57:43 lab1 kernel: 
Nov 23 14:57:43 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:45 lab1 last message repeated 187 times
Nov 23 14:57:46 lab1 kernel: 
Nov 23 14:57:46 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:57:58 lab1 last message repeated 801 times
Nov 23 14:57:58 lab1 kernel: 
Nov 23 14:57:58 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:58:29 lab1 last message repeated 1891 times
Nov 23 14:58:29 lab1 last message repeated 50 times
Nov 23 14:58:29 lab1 kernel: 
Nov 23 14:58:29 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:58:55 lab1 last message repeated 1640 times
Nov 23 14:58:56 lab1 kernel: 
Nov 23 14:58:56 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:59:27 lab1 last message repeated 1940 times
Nov 23 14:59:43 lab1 last message repeated 1051 times
Nov 23 14:59:43 lab1 kernel: 
Nov 23 14:59:43 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 14:59:57 lab1 last message repeated 825 times
Nov 23 14:59:57 lab1 kernel: 
Nov 23 14:59:57 lab1 kernel: ucom_outwakeup:1009: sc = 0xffffff0003052858
Nov 23 15:00:00 lab1 newsyslog[926]: logfile turned over due to size>100K
Nov 23 15:00:00 lab1 last message repeated 208 times

I believe the problem occurs whenever you see a message like this:
Nov 23 14:57:16 lab1 kernel: ucom_get_data:1064: cnt=64

>From a look at the code it looks like the largest uftdi frame is 64 characters (UFTDI_[IO]BUFSIZE in uftdi.c).  Perhaps it is an off by one bug?

-Corey Smith

More information about the freebsd-usb mailing list