problem writing to umass device

Alexander Best alexbestms at math.uni-muenster.de
Wed Jul 29 23:28:36 UTC 2009


here are some input/output benchmark measurements i did. don't know why the
device returned the slow result you noticed. but the following values seem
quite reasonable. maybe the previous results turned out so bad, because in the
background the writes which `cp` requested were still being processed although
`cp` was no longer active. so `dd` had no exclusive access to /dev/da0 and
probably a much lower priority than the writes `cp` requested.

write speed:
------------
[arundel at otaku /usr/home/arundel]$ dd if=/dev/zero of=/dev/da0 count=2048
2048+0 records in
2048+0 records out
1048576 bytes transferred in 5.899281 secs (177746 bytes/sec)
[arundel at otaku /usr/home/arundel]$ dd if=/dev/zero of=/dev/da0 bs=1m count=50
50+0 records in
50+0 records out
52428800 bytes transferred in 6.714179 secs (7808669 bytes/sec)
[arundel at otaku /usr/home/arundel]$ dd if=/dev/zero of=/dev/da0 bs=2m count=25
25+0 records in
25+0 records out
52428800 bytes transferred in 6.418867 secs (8167921 bytes/sec)
[arundel at otaku /usr/home/arundel]$ dd if=/dev/zero of=/dev/da0 bs=5m count=10
10+0 records in
10+0 records out
52428800 bytes transferred in 6.448783 secs (8130030 bytes/sec)
[arundel at otaku /usr/home/arundel]$ dd if=/dev/zero of=/dev/da0 bs=10m count=5
5+0 records in
5+0 records out
52428800 bytes transferred in 6.462789 secs (8112411 bytes/sec)


read speed:
-----------
[arundel at otaku /usr/home/arundel]$ dd if=/dev/da0 of=/dev/null count=2048
2048+0 records in
2048+0 records out
1048576 bytes transferred in 1.461135 secs (717645 bytes/sec)
[arundel at otaku /usr/home/arundel]$ dd if=/dev/da0 of=/dev/null bs=10m count=5
5+0 records in
5+0 records out
52428800 bytes transferred in 9.399185 secs (5578016 bytes/sec)
[arundel at otaku /usr/home/arundel]$ dd if=/dev/da0 of=/dev/null bs=5m count=10
10+0 records in
10+0 records out
52428800 bytes transferred in 9.394816 secs (5580610 bytes/sec)
[arundel at otaku /usr/home/arundel]$ dd if=/dev/da0 of=/dev/null bs=2m count=25
25+0 records in
25+0 records out
52428800 bytes transferred in 9.498048 secs (5519955 bytes/sec)
[arundel at otaku /usr/home/arundel]$ dd if=/dev/da0 of=/dev/null bs=1m count=50
50+0 records in
50+0 records out
52428800 bytes transferred in 9.434601 secs (5557077 bytes/sec)


so. i've blanked the device using dd without any errors. i formated it then
tried the following with hw.usb.umass.debug=-1:

1. mount
2. copy files
3. umount (which hung)

i've mailed you the ouput in a separate mail. two more things i noticed:

1. while copying files to the device i noticed that harddrive access which was
being performed by fsck completely stopped until i detached the usb device.

2. in addition to not being able to attach a usb device again, `sysctl` got
stuck after the following output:

kern.ostype: FreeBSD
kern.osrelease: 8.0-BETA2
kern.osrevision: 199506
kern.version: FreeBSD 8.0-BETA2 #0 r195923M: Tue Jul 28 22:20:15 CEST 2009
    root at otaku:/usr/obj/usr/src/sys/ARUNDEL

kern.maxvnodes: 100000
kern.maxproc: 6164
kern.maxfiles: 12328
kern.argmax: 262144
kern.securelevel: -1
kern.hostname: otaku
kern.hostid: 1391670824
kern.clockrate: { hz = 1000, tick = 1000, profhz = 2000, stathz = 133 }
kern.posix1version: 200112
kern.ngroups: 1023
kern.job_control: 1
kern.saved_ids: 0
kern.boottime: { sec = 1248902591, usec = 78085 } Wed Jul 29 23:23:11 2009
kern.domainname:
kern.osreldate: 800106
kern.bootfile: /boot/kernel/kernel
kern.maxfilesperproc: 11095
kern.maxprocperuid: 5547
kern.ipc.maxsockbuf: 262144
kern.ipc.sockbuf_waste_factor: 8
kern.ipc.somaxconn: 128
kern.ipc.max_linkhdr: 40
kern.ipc.max_protohdr: 40
kern.ipc.max_hdr: 80
kern.ipc.max_datalen: 120
kern.ipc.nmbjumbo16: 3200
kern.ipc.nmbjumbo9: 6400
kern.ipc.nmbjumbop: 12800
kern.ipc.nmbclusters: 25600
kern.ipc.piperesizeallowed: 1
kern.ipc.piperesizefail: 0
kern.ipc.pipeallocfail: 0
kern.ipc.pipefragretry: 0
kern.ipc.pipekva: 163840
kern.ipc.maxpipekva: 16777216
kern.ipc.msgseg: 2048
kern.ipc.msgssz: 8
kern.ipc.msgtql: 40
kern.ipc.msgmnb: 2048
kern.ipc.msgmni: 40
kern.ipc.msgmax: 16384
kern.ipc.semaem: 16384
kern.ipc.semvmx: 32767
kern.ipc.semusz: 136
kern.ipc.semume: 10
kern.ipc.semopm: 100
kern.ipc.semmsl: 60
kern.ipc.semmnu: 30
kern.ipc.semmns: 60
kern.ipc.semmni: 10
kern.ipc.semmap: 30
kern.ipc.shm_allow_removed: 1
kern.ipc.shm_use_phys: 0
kern.ipc.shmall: 32768
kern.ipc.shmseg: 512
kern.ipc.shmmni: 192
kern.ipc.shmmin: 1
kern.ipc.shmmax: 67108864
kern.ipc.maxsockets: 25600
kern.ipc.numopensockets: 98
kern.ipc.nsfbufsused: 0
kern.ipc.nsfbufspeak: 6
kern.ipc.nsfbufs: 6656
kern.dummy: 0
kern.ps_strings: 3217031152
kern.usrstack: 3217031168
kern.logsigexit: 1
kern.iov_max: 1024
kern.hostuuid: 00000000-0000-0000-0000-001a4d4bb4eb
kern.cam.cam_srch_hi: 0
kern.cam.scsi_delay: 2000
kern.cam.cd.retry_count: 4
kern.cam.cd.changer.max_busy_seconds: 15
kern.cam.cd.changer.min_busy_seconds: 5
kern.cam.cd.0.minimum_cmd_size: 10
kern.cam.ada.ada_send_ordered: 1
kern.cam.ada.default_timeout: 30
kern.cam.ada.retry_count: 4
kern.cam.da.da_send_ordered: 1
kern.cam.da.default_timeout: 60
kern.cam.da.retry_count: 4
kern.cam.da.0.minimum_cmd_size: 10

i guess the next line would have been usb related.

cheers.
alex

Hans Petter Selasky schrieb am 2009-07-29:
> On Wednesday 29 July 2009 22:25:05 Alexander Best wrote:
> > i have a problem with the following device:

> > ugen7.2: <Meizu   Electronics> at usbus7
> > umass0: <Meizu   Electronics MiniPlayer, class 0/0, rev 2.00/1.00,
> > addr 2>
> > on usbus7
> > umass0:  SCSI over Bulk-Only; quirks = 0x4400
> > umass0:7:0:-1: Attached to scbus7
> > da0 at umass-sim0 bus 0 target 0 lun 0
> > da0: <  > Removable Direct Access SCSI-2 device
> > da0: 40.000MB/s transfers
> > da0: 3864MB (7913472 512 byte sectors: 255H 63S/T 492C)

> > i haven't used it for quite a while, but it used to work just fine
> > (yes
> > with usb2). but since then i've updated my kernel a couple of times
> > and now
> > i'm getting these errors. i can mount the device just fine, but if
> > i try to
> > copy files onto it i get the following error messages:

> > Jul 28 11:22:07 otaku kernel:
> > g_vfs_done():da0[WRITE(offset=54083584,
> > length=65536)]error = 5
> > Jul 28 11:22:07 otaku kernel:
> > g_vfs_done():da0[WRITE(offset=54149120,
> > length=65536)]error = 5
> > Jul 28 11:22:07 otaku kernel:
> > g_vfs_done():da0[WRITE(offset=54214656,
> > length=65536)]error = 5
> > Jul 28 11:22:07 otaku kernel:
> > g_vfs_done():da0[WRITE(offset=54280192,
> > length=32768)]error = 5
> > Jul 28 11:22:07 otaku kernel:
> > g_vfs_done():da0[WRITE(offset=54312960,
> > length=16384)]error = 5
> > Jul 28 11:22:07 otaku kernel:
> > g_vfs_done():da0[WRITE(offset=54329344,
> > length=65536)]error = 5
> > Jul 28 11:22:07 otaku kernel:
> > g_vfs_done():da0[WRITE(offset=54394880,
> > length=65536)]error = 5
> > Jul 28 11:22:07 otaku kernel:
> > g_vfs_done():da0[WRITE(offset=54460416,
> > length=65536)]error = 5
> > Jul 28 11:22:07 otaku kernel:
> > g_vfs_done():da0[WRITE(offset=54525952,
> > length=65536)]error = 5
> > Jul 28 11:22:07 otaku kernel:
> > g_vfs_done():da0[WRITE(offset=54591488,
> > length=65536)]error = 5
> > Jul 28 11:22:07 otaku kernel:
> > g_vfs_done():da0[WRITE(offset=54657024,
> > length=16384)]error = 5
> > Jul 28 11:22:07 otaku kernel: g_vfs_done():da0[WRITE(offset=512,
> > length=512)]error = 5
> > Jul 28 11:22:07 otaku kernel: g_vfs_done():da0[WRITE(offset=24576,
> > length=4096)]error = 5
> > Jul 28 11:22:07 otaku kernel: g_vfs_done():da0[WRITE(offset=28672,
> > length=4096)]error = 5
> > Jul 28 11:22:07 otaku kernel:
> > g_vfs_done():da0[WRITE(offset=1024000,
> > length=4096)]error = 5
> > Jul 28 11:22:07 otaku kernel:
> > g_vfs_done():da0[WRITE(offset=1028096,
> > length=4096)]error = 5
> > Jul 28 11:22:07 otaku kernel:
> > g_vfs_done():da0[WRITE(offset=38502400,
> > length=16384)]error = 5
> > Jul 28 11:22:07 otaku kernel:
> > g_vfs_done():da0[WRITE(offset=39370752,
> > length=16384)]error = 5
> > Jul 28 11:22:07 otaku kernel: fsync: giving up on dirty
> > Jul 28 11:22:07 otaku kernel: 0xcc0aa6b8: tag msdosfs, type VREG
> > Jul 28 11:22:07 otaku kernel: usecount 1, writecount 0, refcount 55
> > mountedhere 0
> > Jul 28 11:22:07 otaku kernel: flags ()
> > Jul 28 11:22:07 otaku kernel: v_object 0xc8a81770 ref 0 pages 212
> > Jul 28 11:22:07 otaku kernel: lock type msdosfs: EXCL by thread
> > 0xcc60a240
> > (pid 19448)
> > Jul 28 11:22:07 otaku kernel: #0 0xc05b5ee0 at __lockmgr_args+0xb90
> > Jul 28 11:22:07 otaku kernel: #1 0xc0647898 at vop_stdlock+0x68
> > Jul 28 11:22:07 otaku kernel: #2 0xc0781fb5 at VOP_LOCK1_APV+0xb5
> > Jul 28 11:22:07 otaku kernel: #3 0xc0664008 at _vn_lock+0x78
> > Jul 28 11:22:07 otaku kernel: #4 0xc0658adb at vget+0xbb
> > Jul 28 11:22:07 otaku kernel: #5 0xc055d4ca at msdosfs_sync+0x17a
> > Jul 28 11:22:07 otaku kernel: #6 0xc06520be at dounmount+0x44e
> > Jul 28 11:22:07 otaku kernel: #7 0xc065262f at unmount+0x2bf
> > Jul 28 11:22:07 otaku kernel: #8 0xc076eb26 at syscall+0x2a6
> > Jul 28 11:22:07 otaku kernel: #9 0xc0752ad0 at
> > Xint0x80_syscall+0x20
> > Jul 28 11:22:07 otaku kernel: startcluster 2230, dircluster 2229,
> > diroffset
> > 96, on dev da0
> > Jul 28 11:22:40 otaku kernel:
> > g_vfs_done():da0[WRITE(offset=53805056,
> > length=65536)]error = 5
> > Jul 28 11:22:40 otaku kernel:
> > g_vfs_done():da0[WRITE(offset=53870592,
> > length=65536)]error = 5
> > Jul 28 11:22:40 otaku kernel:
> > g_vfs_done():da0[WRITE(offset=53936128,
> > length=65536)]error = 5
> > Jul 28 11:22:40 otaku kernel:
> > g_vfs_done():da0[WRITE(offset=54001664,
> > length=65536)]error = 5
> > Jul 28 11:22:40 otaku kernel:
> > g_vfs_done():da0[WRITE(offset=54067200,
> > length=65536)]error = 5
> > Jul 28 11:22:40 otaku kernel:
> > g_vfs_done():da0[WRITE(offset=54132736,
> > length=65536)]error = 5
> > Jul 28 11:22:40 otaku kernel:
> > g_vfs_done():da0[WRITE(offset=54198272,
> > length=65536)]error = 5
> > Jul 28 11:22:40 otaku kernel:
> > g_vfs_done():da0[WRITE(offset=54263808,
> > length=65536)]error = 5
> > Jul 28 11:22:40 otaku kernel:
> > g_vfs_done():da0[WRITE(offset=54329344,
> > length=65536)]error = 5
> > Jul 28 11:22:40 otaku kernel:
> > g_vfs_done():da0[WRITE(offset=54394880,
> > length=65536)]error = 5
> > Jul 28 11:22:40 otaku kernel:
> > g_vfs_done():da0[WRITE(offset=54460416,
> > length=65536)]error = 5
> > Jul 28 11:22:40 otaku kernel:
> > g_vfs_done():da0[WRITE(offset=54525952,
> > length=65536)]error = 5

> > might the device's ram be broken? this is the result of `dd
> > if=/dev/da0
> > of=/dev/null`:

> > dd: /dev/da0: Input/output error
> > 1067+0 records in
> > 1067+0 records out
> > 546304 bytes transferred in 235.522107 secs (2320 bytes/sec)
>                                                   ^^ terribly slow
>                                                   disk ?


> > i attached the device to a windows xp box and ran scandisk. that
> > didn't
> > reveal any problems however.


> Hi,

> Try enabling umass debugging:

> sysctl hw.usb.umass.debug=-1

> Not sure if this might be a CAM layer regression.

> --HPS


More information about the freebsd-usb mailing list