Intermittent pauses copying from one usb drive to another
Donald Allen
donaldcallen at gmail.com
Sat Feb 5 13:57:29 UTC 2011
I've discussed problems with FreeBSD and usb sata drives on this list
in the past (as recently as last September), and have given up on
FreeBSD as a result of the usb disk problems (I do my backups with usb
drives) and other usb-related issues. But I've now replaced the usb
enclosures I was using at that time and have acquired some Toshiba usb
drives, so with this new equipment, I thought I'd give FreeBSD another
try, since generally I prefer it to Linux. But I'm having problems
again.
Plugging in the Toshiba drives produces entries like this in /var/log/message:
Feb 5 07:22:07 octavian root: Unknown USB device: vendor 0x0480
product 0xa003 bus uhub1
Feb 5 07:22:07 octavian kernel: ugen1.6: <Toshiba> at usbus1
Feb 5 07:22:07 octavian kernel: umass0: <Bulk Only Interface> on usbus1
Feb 5 07:22:07 octavian kernel: umass0: SCSI over Bulk-Only; quirks = 0x0000
Feb 5 07:22:08 octavian kernel: umass0:0:0:-1: Attached to scbus0
Feb 5 07:22:45 octavian root: Unknown USB device: vendor 0x0480
product 0xa003 bus uhub1
Feb 5 07:22:45 octavian kernel: ugen1.7: <Toshiba> at usbus1
Feb 5 07:22:45 octavian kernel: umass1: <Bulk Only Interface> on usbus1
Feb 5 07:22:45 octavian kernel: umass1: SCSI over Bulk-Only; quirks = 0x0000
Feb 5 07:22:46 octavian kernel: umass1:1:1:-1: Attached to scbus1
Feb 5 07:23:18 octavian kernel: ugen1.6: <Toshiba> at usbus1 (disconnected)
Feb 5 07:23:18 octavian kernel: umass0: at uhub1, port 5, addr 6 (disconnected)
Feb 5 07:23:18 octavian kernel: (probe0:umass-sim0:0:0:0): AutoSense failed
Feb 5 07:23:20 octavian root: Unknown USB device: vendor 0x0480
product 0xa003 bus uhub1
Feb 5 07:23:20 octavian kernel: ugen1.6: <Toshiba> at usbus1
Feb 5 07:23:20 octavian kernel: umass0: <Bulk Only Interface> on usbus1
Feb 5 07:23:20 octavian kernel: umass0: SCSI over Bulk-Only; quirks = 0x0000
Feb 5 07:23:21 octavian kernel: umass0:0:0:-1: Attached to scbus0
Feb 5 07:23:22 octavian kernel: da0 at umass-sim0 bus 0 scbus0 target 0 lun 0
Feb 5 07:23:22 octavian kernel: da0: <Toshiba External USB HDD >
Fixed Direct Access SCSI-4 device
Feb 5 07:23:22 octavian kernel: da0: 40.000MB/s transfers
Feb 5 07:23:22 octavian kernel: da0: 305245MB (625142448 512 byte
sectors: 255H 63S/T 38913C)
Feb 5 07:23:56 octavian kernel: ugen1.7: <Toshiba> at usbus1 (disconnected)
Feb 5 07:23:56 octavian kernel: umass1: at uhub1, port 6, addr 7 (disconnected)
Feb 5 07:23:56 octavian kernel: (probe1:umass-sim1:1:0:0): AutoSense failed
Feb 5 07:23:58 octavian root: Unknown USB device: vendor 0x0480
product 0xa003 bus uhub1
Feb 5 07:23:58 octavian kernel: ugen1.7: <Toshiba> at usbus1
Feb 5 07:23:58 octavian kernel: umass1: <Bulk Only Interface> on usbus1
Feb 5 07:23:58 octavian kernel: umass1: SCSI over Bulk-Only; quirks = 0x0000
Feb 5 07:23:59 octavian kernel: umass1:1:1:-1: Attached to scbus1
Feb 5 07:23:59 octavian sudo: dca : TTY=pts/0 ;
PWD=/usr/home/dca ; USER=root ; COMMAND=/sbin/mount /dev/da0s2a
Primary
Feb 5 07:23:59 octavian kernel: da1 at umass-sim1 bus 1 scbus1 target 0 lun 0
Feb 5 07:23:59 octavian kernel: da1: <Toshiba External USB HDD >
Fixed Direct Access SCSI-4 device
Feb 5 07:23:59 octavian kernel: da1: 40.000MB/s transfers
Feb 5 07:23:59 octavian kernel: da1: 305245MB (625142448 512 byte
sectors: 255H 63S/T 38913C)
There were two drives plugged in here, once. So the 'disconnect'
messages are odd -- I did not unplug the drives.
Each of the drives has an approx. 160 Gb FreeBSD slice, with a single
partition, 'a'. You can see the mount of da0s2a above (slice 1 is a
Linux ext2 partition). What I am attempting to do is to rsync da0s2a
to da1s2a, which was freshly newfs'ed when I started this. The
behavior I see is that the disk lights blink for awhile, indicating
copying going on, and then they stop for quite awhile, a minute or so.
Then activity resumes, You can see what I'm talking about in the
vmstat output below:
procs memory page disks faults cpu
r b w avm fre flt re pi po fr sr ad4 da0 da1 in
sy cs us sy id
1 0 0 824M 62M 73 0 0 0 46 4909 1 196 231 2131
25494 21503 6 8 86
0 0 0 840M 81M 150 0 0 0 140 2471 1 129 412 1811
13128 19859 5 9 86
0 0 0 850M 96M 114 0 0 0 101 2483 0 91 246 1334
10677 13301 4 5 91
0 0 0 852M 64M 72 0 0 0 79 2466 2 126 199 1465
15157 14908 3 6 90
0 0 0 849M 53M 44 0 0 0 32 1230 1 78 216 1107
8990 11465 3 5 92
0 0 0 855M 60M 93 0 0 0 152 1235 0 63 217 1016
6572 10156 3 4 93
0 0 0 857M 90M 47 0 0 0 76 6154 0 178 205 1935
23283 19444 5 8 87
0 0 0 853M 80M 47 0 0 0 73 6175 0 203 218 2185
27024 21755 6 8 87
0 0 0 854M 93M 93 0 0 0 79 2462 0 92 215 1261
10889 12570 4 6 91
0 0 0 854M 55M 58 0 0 0 89 4907 2 189 210 2086
24838 20550 5 9 86
0 0 0 854M 94M 31 0 0 0 40 3676 1 86 90 945
12099 9621 3 4 93
0 0 0 854M 94M 58 0 0 0 51 0 0 0 12 60
1066 987 1 1 98
0 0 0 854M 94M 33 0 0 0 27 0 0 0 0 13
1344 743 2 1 98
0 0 0 854M 78M 422 10 0 0 58 0 9 0 0 188
5559 2445 11 1 88
0 0 0 854M 78M 60 0 0 0 49 0 1 0 0 15
1450 779 2 1 98
0 0 0 850M 78M 34 0 0 0 32 0 0 0 0 24
1700 971 2 1 97
0 0 0 850M 78M 31 0 0 0 25 0 8 0 0 22
1307 773 2 1 97
0 0 0 850M 99M 71 1 0 0 336 1323 1 23 23 255
3869 2988 2 2 96
0 0 0 850M 77M 42 0 0 0 62 4917 1 178 189 1943
23430 19194 5 7 88
0 0 0 850M 83M 49 0 0 0 85 6125 1 193 205 2132
26317 21015 5 9 86
1 0 0 860M 63M 628 1 1 0 598 2458 3 131 273 1654
18534 17826 7 8 85
0 0 0 860M 60M 855 0 0 0 797 0 1 0 34 149
2661 2116 5 2 93
0 0 0 870M 101M 327 0 0 0 183 1309 2 0 0 36
1953 1050 3 1 95
0 0 0 866M 107M 79 0 0 0 215 0 0 0 1 14
1063 689 2 1 98
1 0 0 866M 106M 164 0 0 0 151 0 2 0 0 30
2655 1168 2 1 97
0 0 0 866M 103M 1648 1 1 0 1570 0 5 0 0 45
3879 1530 7 2 92
0 0 0 866M 103M 73 0 0 0 50 0 1 0 0 14
1399 767 2 1 97
0 0 0 866M 103M 31 0 0 0 28 0 1 0 0 14
1235 766 1 1 98
0 0 0 862M 69M 285 1 0 0 365 1371 3 102 242 1304
13763 14730 5 8 88
0 0 0 867M 100M 129 0 0 0 67 2473 1 108 364 1588
11311 17239 3 8 89
0 0 0 867M 93M 39 0 0 0 60 3667 0 124 201 1576
16721 15353 4 6 90
0 0 0 865M 70M 295 0 1 0 337 4919 1 177 191 1946
27949 20439 7 8 85
0 0 0 859M 66M 1390 0 0 0 899 2453 10 137 436 2078
24631 25737 15 11 74
1 0 0 859M 87M 263 0 0 0 505 2542 0 102 303 1501
17343 17390 6 7 86
0 0 0 853M 84M 483 0 0 0 467 0 5 15 51 226
3275 3270 5 2 93
0 0 0 857M 62M 494 0 0 0 463 0 3 96 450 1607
15228 20137 8 9 83
0 0 0 857M 62M 1195 0 0 0 1184 0 0 0 76 288
9173 5305 8 3 88
0 0 0 857M 61M 1100 0 0 0 1073 0 2 0 0 41
7347 2740 7 2 91
0 0 0 857M 60M 258 0 0 0 236 0 1 0 0 32
5502 1971 3 2 95
2 0 0 857M 104M 1429 0 0 0 1466 1418 0 0 0 25
4264 1783 6 2 92
2 0 0 868M 97M 493 0 0 0 323 0 2 0 0 57
9525 3167 6 2 92
2 0 0 858M 102M 1267 0 0 0 1361 0 1 0 0 57
10980 3867 10 3 88
0 0 0 858M 102M 682 0 0 0 678 0 0 0 0 27
4420 1771 6 1 93
0 0 0 859M 97M 623 0 0 0 573 0 1 12 34 159
3460 2886 6 2 92
2 0 0 862M 84M 452 0 0 0 160 0 12 0 0 149
10580 3733 14 3 84
2 0 0 867M 81M 177 0 0 0 92 0 1 0 9 61
2059 1253 5 1 94
0 0 0 867M 81M 48 0 0 0 39 0 1 0 0 13
1248 733 2 1 97
0 0 0 867M 81M 177 0 0 0 169 0 5 0 0 28
3775 1537 3 1 95
0 0 0 877M 73M 769 0 0 0 536 0 2 0 0 38
2866 1386 5 1 94
0 0 0 877M 73M 31 0 0 0 24 0 1 0 0 13
1167 715 1 1 98
2 0 0 907M 55M 197 0 0 0 54 0 2 66 246 908
8663 11652 4 5 91
0 0 0 893M 67M 773 0 0 0 1083 1662 3 104 456 1715
10793 19469 7 8 85
0 0 0 898M 65M 104 0 0 0 319 1276 1 108 393 1636
11315 17744 4 7 89
0 0 0 885M 69M 214 0 0 0 320 1258 1 103 442 1731
14282 20084 6 8 86
0 0 0 864M 71M 613 0 0 0 540 1225 1 45 100 611
7012 6815 4 3 93
procs memory page disks faults cpu
r b w avm fre flt re pi po fr sr ad4 da0 da1 in
sy cs us sy id
0 0 0 864M 70M 250 0 0 0 240 0 1 0 69 260
6180 4208 4 2 94
0 0 0 864M 70M 61 0 0 0 58 0 4 0 3 30
1885 1008 2 1 97
2 0 0 864M 70M 33 0 0 0 25 0 0 0 0 33
2742 1197 2 1 97
0 0 0 864M 69M 63 0 0 0 27 0 1 0 0 29
1881 1031 2 1 97
0 0 0 864M 69M 58 0 0 0 50 0 2 0 0 25
1495 819 2 1 97
The copy did eventually complete, but took forever. Probably relevant
is that I am seeing the following in /var/log/messages during the
copy:
Feb 5 07:26:11 octavian kernel: (da0:umass-sim0:0:0:0): AutoSense failed
Feb 5 07:26:11 octavian kernel:
g_vfs_done():da0s2a[WRITE(offset=53554888704, length=16384)]error = 5
Feb 5 07:26:11 octavian kernel:
g_vfs_done():da0s2a[WRITE(offset=114688, length=16384)]error = 5
Feb 5 07:26:11 octavian kernel:
g_vfs_done():da0s2a[WRITE(offset=52976959488, length=16384)]error = 5
Feb 5 07:26:11 octavian kernel:
g_vfs_done():da0s2a[WRITE(offset=53362245632, length=16384)]error = 5
Feb 5 07:26:11 octavian kernel:
g_vfs_done():da0s2a[WRITE(offset=53362262016, length=16384)]error = 5
Feb 5 07:26:11 octavian kernel:
g_vfs_done():da0s2a[WRITE(offset=53362278400, length=16384)]error = 5
Feb 5 07:26:11 octavian kernel:
g_vfs_done():da0s2a[READ(offset=53375156224, length=131072)]error = 5
Feb 5 07:28:05 octavian kernel: (da1:umass-sim1:1:0:0): AutoSense failed
Feb 5 07:28:05 octavian kernel:
g_vfs_done():da1s2a[WRITE(offset=156466298880, length=16384)]error = 5
Feb 5 07:28:05 octavian kernel:
g_vfs_done():da1s2a[WRITE(offset=156501897216, length=2048)]error = 5
Feb 5 07:28:05 octavian kernel:
g_vfs_done():da1s2a[WRITE(offset=156501899264, length=2048)]error = 5
Feb 5 07:28:05 octavian kernel:
g_vfs_done():da1s2a[WRITE(offset=156501917696, length=14336)]error = 5
Feb 5 07:28:05 octavian kernel:
g_vfs_done():da1s2a[WRITE(offset=156501932032, length=2048)]error = 5
Feb 5 07:28:05 octavian kernel:
g_vfs_done():da1s2a[WRITE(offset=156501934080, length=2048)]error = 5
Feb 5 07:28:05 octavian kernel:
g_vfs_done():da1s2a[WRITE(offset=156501936128, length=4096)]error = 5
Feb 5 07:28:05 octavian kernel:
g_vfs_done():da1s2a[WRITE(offset=156501940224, length=2048)]error = 5
Feb 5 07:28:05 octavian kernel:
g_vfs_done():da1s2a[WRITE(offset=156501942272, length=2048)]error = 5
Feb 5 07:28:05 octavian kernel:
g_vfs_done():da1s2a[WRITE(offset=156501944320, length=2048)]error = 5
Feb 5 07:28:05 octavian kernel:
g_vfs_done():da1s2a[WRITE(offset=156501946368, length=2048)]error = 5
Feb 5 07:28:05 octavian kernel:
g_vfs_done():da1s2a[WRITE(offset=156501948416, length=2048)]error = 5
Feb 5 07:28:05 octavian kernel:
g_vfs_done():da1s2a[WRITE(offset=156501950464, length=16384)]error = 5
Feb 5 07:28:05 octavian kernel:
g_vfs_done():da1s2a[WRITE(offset=156501966848, length=6144)]error = 5
Feb 5 07:28:05 octavian kernel:
g_vfs_done():da1s2a[WRITE(offset=156501972992, length=6144)]error = 5
Feb 5 07:28:05 octavian kernel:
g_vfs_done():da1s2a[WRITE(offset=156501979136, length=2048)]error = 5
Feb 5 07:28:05 octavian kernel:
g_vfs_done():da1s2a[WRITE(offset=156501981184, length=2048)]error = 5
Feb 5 07:28:05 octavian kernel:
g_vfs_done():da1s2a[WRITE(offset=156501983232, length=8192)]error = 5
I'm ready to give up and go back to Linux -- again!! -- but thought
I'd see if any of you have some bright ideas. I should note that I am
running 8.1 release on a vanilla cheap HP box (dual-core AMD Athlon, 2
Gb memory, 320 Gb 7200 rpm sata drive). Since 8.2 is imminent, I am
wondering if what I am seeing here has been observed before and
perhaps there are some improvements in the usb code for 8.2??
/Don Allen
More information about the freebsd-usb
mailing list