Hi,
I use a usb-ide enclosure for backup. The enclosure has a cypress chip:
T: Bus=01 Lev=01 Prnt=01 Port=03 Cnt=01 Dev#= 2 Spd=480 MxCh= 0
D: Ver= 2.00 Cls=00(>ifc ) Sub=00 Prot=00 MxPS=64 #Cfgs= 1
P: Vendor=04b4 ProdID=6830 Rev= 0.01
S: Manufacturer=Cypress Semiconductor
S: Product=USB2.0 Storage Device
S: SerialNumber=DEF1076A66AF
C:* #Ifs= 1 Cfg#= 1 Atr=c0 MxPwr= 0mA
I: If#= 0 Alt= 0 #EPs= 2 Cls=08(stor.) Sub=06 Prot=50 Driver=usb-storage
E: Ad=02(O) Atr=02(Bulk) MxPS= 512 Ivl=0ms
E: Ad=88(I) Atr=02(Bulk) MxPS= 512 Ivl=0ms
During backup the speed is inconsistent: most of the time it is ok but all
10-20 secs the backup comes to halt. In top(1) I can see that the percentage
used for iowait goes up to 99% during this time. After a few seconds iowait
drops back to <10% and the backup continues.
Often the backup is aborted after a few hours with a device disconnect and
a oops (see below).
I tried this with 2.6.11-rc4-bk6 and some other 2.6.11-rc kernels.
This happens just on one machine, on another machine with identical mainboard,
identical usb-controller and the same disk/enclosure this does not happen.
The only thing that is different is that the machine where it is working has
a slower cpu (Celeron 650 instead PIII 1GHz) and less RAM.
Both machines were otherwise working stable with a longer uptime (>14 days).
So I think it might be a timing issue (not the oops but the problems before).
I already tried adding the 110usec delay that the Genesys devices need but
that didn't help.
Can anyone help making my backup reliable?
Kind regards,
Gerd
If usb-storage debugging is on something like this getts logged every time
the slowdown happens:
usb-storage: *** thread sleeping.
usb-storage: queuecommand called
usb-storage: *** thread awakened.
usb-storage: Command READ_10 (10 bytes)
usb-storage: 28 00 11 00 0f 6f 00 00 10 00
usb-storage: Bulk Command S 0x43425355 T 0x52c72 L 8192 F 128 Trg 0 LUN 0 CL 10
usb-storage: usb_stor_bulk_transfer_buf: xfer 31 bytes
usb-storage: Status code 0; transferred 31/31
usb-storage: -- transfer complete
usb-storage: Bulk command transfer result=0
usb-storage: usfer result=0
usb-storage: usb_stor_bulk_transfer_sglist: xfer 8192 bytes, 2 entries
usb-storage: Status code 0; transferred 8192/8192
usb-storage: -- transfer complete
usb-storage: Bulk data transfer result 0x0
usb-storage: Attempting to get CSW...
usb-storage: usb_stor_bulk_transfer_buf: xfer 13 bytes
usb-storage: Status code 0; transferred 13/13
usb-storage: -- transfer complete
usb-storage: Bulk status result = 0
usb-storage: Bulk Status S 0x53425355 T 0x52cd7 R 0 Stat 0x0
usb-storage: scsi cmd done, result=0x0
usb-storage: *** thread sleeping.
sometimes something like this gets logged:
usb-storage: *** thread awakened.
usb-storage: Command READ_10 (10 bytes)
usb-storage: 28 00 0c b1 7f 87 00 00 f0 00
usb-storage: Bulk Command S 0x43425355 T 0x3809 L 122880 F 128 Trg 0 LUN 0 CL 10
usb-storage: usb_stor_bulk_transfer_buf: xfer 31 bytes
usb-storage: Status code 0; transferred 31/31
usb-storage: -- transfer complete
usb-storage: Bulk command transfer result=0
usb-storage: usb_stor_bulk_transfer_sglist: xfer 122880 bytes, 30 entries
usb-storage: Status code -71; transferred 103936/122880
usb-storage: -- unknown error
usb-storage: Bulk data transfer result 0x4
usb-storage: -- transport indicates error, resetting
usb-storage: usb_stor_Bulk_reset called
usb-storage: usb_stor_control_msg: rq=ff rqtype=21 value=0000 index=00 len=0
usb-storage: Soft reset: clearing bulk-in endpoint halt
usb-storage: usb_stor_control_msg: rq=01 rqtype=02 value=0000 index=88 len=0
usb-storage: usb_stor_clear_halt: result = 0
usb-storage: Soft reset: clearing bulk-out endpoint halt
usb-storage: usb_stor_control_msg: rq=01 rqtype=02 value=0000 index=02 len=0
usb-storage: usb_stor_clear_halt: result = 0
usb-storage: Soft reset done
usb-storage: scsi cmd done, result=0x70000
usb-storage: *** thread sleeping.
and sometimes this:
usb-storage: *** thread awakened.
usb-storage: Command READ_10 (10 bytes)
usb-storage: 28 00 0b f7 99 97 00 00 f0 00
usb-storage: Bulk Command S 0x43425355 T 0x6fd2 L 122880 F 128 Trg 0 LUN 0 CL 10
usb-storage: usb_stor_bulk_transfer_buf: xfer 31 bytes
usb-storage: Status code 0; transferred 31/31
usb-storage: -- transfer complete
usb-storage: Bulk command transfer result=0
usb-storage: usb_stor_bulk_transfer_sglist: xfer 122880 bytes, 30 entries
usb-storage: Status code -121; transferred 121869/122880
usb-storage: -- short read transfer
usb-storage: Bulk data transfer result 0x1
usb-storage: Attempting to get CSW...
usb-storage: usb_stor_bulk_transfer_buf: xfer 13 bytes
usb-storage: command_abort called
usb-storage: usb_stor_stop_transport called
usb-storage: -- cancelling URB
usb-storage: Status code -104; transferred 0/13
usb-storage: -- transfer cancelled
usb-storage: Bulk status result = 4
usb-storage: -- command was aborted
usb-storage: usb_stor_Bulk_reset called
usb-storage: usb_stor_control_msg: rq=ff rqtype=21 value=0000 index=00 len=0
usb-storage: Soft reset: clearing bulk-in endpoint halt
usb-storage: usb_stor_control_msg: rq=01 rqtype=02 value=0000 index=88 len=0
usb-storage: usb_stor_clear_halt: result = 0
usb-storage: Soft reset: clearing bulk-out endpoint halt
usb-storage: usb_stor_control_msg: rq=01 rqtype=02 value=0000 index=02 len=0
usb-storage: usb_stor_clear_halt: result = 0
usb-storage: Soft reset done
usb-storage: scsi command aborted
usb-storage: *** thread sleeping.
after a while the backup usually comes to a halt:
usb-storage: *** thread awakened.
usb-storage: Command READ_10 (10 bytes)
usb-storage: 28 00 05 c0 72 5f 00 00 f0 00
usb-storage: Bulk Command S 0x43425355 T 0x8e471 L 122880 F 128 Trg 0 LUN 0 CL
10
usb-storage: usb_stor_bulk_transfer_buf: xfer 31 bytes
usb-storage: Status code -71; transferred 0/31
usb-storage: -- unknown error
usb-storage: Bulk command transfer result=4
usb-storage: -- transport indicates error, resetting
usb-storage: usb_stor_Bulk_reset called
usb-storage: usb_stor_control_msg: rq=ff rqtype=21 value=0000 index=00 len=0
usb-storage: Soft reset failed: -71
usb-storage: scsi cmd done, result=0x70000
usb-storage: *** thread sleeping.
SCSI error : <0 0 0 0> return code = 0x70000
end_request: I/O error, dev sda, sector 96498271
usb-storage: queuecommand called
usb-storage: *** thread awakened.
[...]
SCSI error : <0 0 0 0> return code = 0x70000
end_request: I/O error, dev sda, sector 96498303
usb-storage: queuecommand called
usb-storage: *** thread awakened.
usb-storage: Command READ_10 (10 bytes)
usb-storage: 28 00 05 c0 72 87 00 00 c8 00
usb-storage: Bulk Command S 0x43425355 T 0x8e476 L 102400 F 128 Trg 0 LUN 0 CL
10
usb-storage: usb_stor_bulk_transfer_buf: xfer 31 bytes
usb-storage: Status code -19; transferred 0/31
usb-storage: -- unknown error
usb-storage: Bulk command transfer result=4
usb-storage: -- transport indicates error, resetting
usb-storage: usb_stor_Bulk_reset called
usb-storage: usb_stor_control_msg: rq=ff rqtype=21 value=0000 index=00 len=0
usb-storage: Soft reset failed: -19
usb-storage: scsi cmd done, result=0x70000
usb-storage: *** thread sleeping.
SCSI error : <0 0 0 0> return code = 0x70000
end_request: I/O error, dev sda, sector 96498311
usb-storage: queuecommand called
usb-storage: storage_disconnect() called
usb-storage: usb_stor_stop_transport called
kobject_hotplug
fill_kobj_path: path = '/class/scsi_device/0:0:0:0'
fill_kobj_path: path =
'/devices/pci0000:00/0000:00:0a.2/usb1/1-4/1-4:1.0/host0/target0:0:0/0:0:0:0'
kobject_hotplug: /sbin/udevsend scsi_device seq=950 HOME=/
PATH=/sbin:/bin:/usr/sbin:/usr/bin ACTION=remove
DEVPATH=/class/scsi_device/0:0:0:0 SUBSYSTEM=scsi_device
usb-storage: *** thread awakened.
usb-storage: No command during disconnect
usb-storage: *** thread sleeping.
kobject 0:0:0:0: cleaning up
kobject sda1: unregistering
kobject_hotplug
fill_kobj_path: path = '/block/sda/sda1'
fill_kobj_path: path =
'/devices/pci0000:00/0000:00:0a.2/usb1/1-4/1-4:1.0/host0/target0:0:0/0:0:0:0'
kobject_hotplug: /sbin/udevsend block seq=951 HOME=/
PATH=/sbin:/bin:/usr/sbin:/usr/bin ACTION=remove DEVPATH=/block/sda/sda1
SUBSYSTEM=block
kobject iosched: unregistering
kobject iosched: cleaning up
kobject queue: unregistering
kobject queue: cleaning up
kobject_hotplug
fill_kobj_path: path = '/block/sda'
fill_kobj_path: path =
'/devices/pci0000:00/0000:00:0a.2/usb1/1-4/1-4:1.0/host0/target0:0:0/0:0:0:0'
kobject_hotplug: /sbin/udevsend block seq=952 HOME=/
PATH=/sbin:/bin:/usr/sbin:/usr/bin ACTION=remove DEVPATH=/block/sda
SUBSYSTEM=block
kobject_hotplug
fill_kobj_path: path =
'/devices/pci0000:00/0000:00:0a.2/usb1/1-4/1-4:1.0/host0/target0:0:0/0:0:0:0'
kobject_hotplug: /sbin/udevsend scsi seq=953 HOME=/
PATH=/sbin:/bin:/usr/sbin:/usr/bin ACTION=remove
DEVPATH=/devices/pci0000:00/0000:00:0a.2/usb1/1-4/1-4:1.0/host0/target0:0:0/0:0:0:0
SUBSYSTEM=scsi
kobject_hotplug
fill_kobj_path: path = '/class/scsi_host/host0'
fill_kobj_path: path = '/devices/pci0000:00/0000:00:0a.2/usb1/1-4/1-4:1.0/host0'
kobject_hotplug: /sbin/udevsend scsi_host seq=954 HOME=/
PATH=/sbin:/bin:/usr/sbin:/usr/bin ACTION=remove DEVPATH=/class/scsi_host/host0
SUBSYSTEM=scsi_host
[...]
kobject sdb1: registering. parent: sdb, set: <NULL>
kobject_hotplug
fill_kobj_path: path = '/block/sdb/sdb1'
fill_kobj_path: path =
'/devices/pci0000:00/0000:00:0a.2/usb1/1-4/1-4:1.0/host1/target1:0:0/1:0:0:0'
kobject_hotplug: /sbin/udevsend block seq=962 HOME=/
PATH=/sbin:/bin:/usr/sbin:/usr/bin ACTION=add DEVPATH=/block/sdb/sdb1
SUBSYSTEM=block
kobject queue: registering. parent: sdb, set: <NULL>
kobject iosched: registering. parent: queue, set: <NULL>
Attached scsi disk sdb at scsi1, channel 0, id 0, lun 0
kobject 1:0:0:0: registering. parent: scsi_device, set: class_obj
kobject_hotplug
fill_kobj_path: path = '/class/scsi_device/1:0:0:0'
fill_kobj_path: path =
'/devices/pci0000:00/0000:00:0a.2/usb1/1-4/1-4:1.0/host1/target1:0:0/1:0:0:0'
kobject_hotplug: /sbin/udevsend scsi_device seq=963 HOME=/
PATH=/sbin:/bin:/usr/sbin:/usr/bin ACTION=add
DEVPATH=/class/scsi_device/1:0:0:0 SUBSYSTEM=scsi_device
usb-storage: queuecommand called
usb-storage: *** thread awakened.
usb-storage: Bad target number (1:0)
usb-storage: scsi cmd done, result=0x40000
usb-storage: *** thread sleeping.
kobject <NULL>: cleaning up
kobject <NULL>: cleaning up
usb-storage: queuecommand called
usb-storage: *** thread awakened.
usb-storage: Bad target number (2:0)
usb-storage: scsi cmd done, result=0x40000
usb-storage: *** thread sleeping.
kobject <NULL>: cleaning up
kobject <NULL>: cleaning up
usb-storage: queuecommand called
usb-storage: *** thread awakened.
usb-storage: Bad target number (3:0)
usb-storage: scsi cmd done, result=0x40000
usb-storage: *** thread sleeping.
kobject <NULL>: cleaning up
kobject <NULL>: cleaning up
usb-storage: queuecommand called
usb-storage: *** thread awakened.
usb-storage: Bad target number (4:0)
usb-storage: scsi cmd done, result=0x40000
usb-storage: *** thread sleeping.
kobject <NULL>: cleaning up
kobject <NULL>: cleaning up
usb-storage: queuecommand called
usb-storage: *** thread awakened.
usb-storage: Bad target number (5:0)
usb-storage: scsi cmd done, result=0x40000
usb-storage: *** thread sleeping.
kobject <NULL>: cleaning up
kobject <NULL>: cleaning up
usb-storage: queuecommand called
usb-storage: *** thread awakened.
usb-storage: Bad target number (6:0)
usb-storage: scsi cmd done, result=0x40000
usb-storage: *** thread sleeping.
kobject <NULL>: cleaning up
kobject <NULL>: cleaning up
usb-storage: queuecommand called
usb-storage: *** thread awakened.
usb-storage: Bad target number (7:0)
usb-storage: scsi cmd done, result=0x40000
usb-storage: *** thread sleeping.
kobject <NULL>: cleaning up
kobject <NULL>: cleaning up
usb-storage: device scan complete
usb-storage: command_abort called
usb-storage: -- nothing to abort
usb-storage: bus_reset called
Unable to handle kernel paging request at virtual address f5df0842
printing eip:
d8b9e61f
*pde = 00000000
Oops: 0000 [#1]
Modules linked in: aes_i586 dm_crypt sd_mod usb_storage nfsd exportfs lockd
sunrpcautofs4
binfmt_misc dm_mod video uhci_hcd ehci_hcd usbcore parport_pc parport
snd_via82xx snd_ac97_codec
snd_mpu401_uart snd_rawmidi 8139too crc32 reiserfs
CPU: 0
EIP: 0060:[<d8b9e61f>] Not tainted VLI
EFLAGS: 00010246 (2.6.11-rc4-bk6)
EIP is at bus_reset+0xaf/0x290 [usb_storage]
eax: f5df06f6 ebx: d4cd6000 ecx: c4c5f034 edx: cf418400
esi: 00000282 edi: cdca0c40 ebp: c2bfbec8 esp: c2bfbe9c
ds: 007b es: 007b ss: 0068
Process scsi_eh_0 (pid: 4041, threadinfo=c2bfa000 task=d7d51aa0)
Stack: d8ba4456 0000006b cdca0c40 c4c5f000 d4cd6000 c2bfbec0 c01207e8 d8ba2eec
cdca0c40 00000282 cdca0c58 c2bfbef8 c0294ebf cdca0c40 000f4c5e 00000293
cdca0c40 c0290b70 cdca0c40 c2bfbf70 cdca0c40 cdca0c40 cdca0c58 c2bfbf1c
Call Trace:
[<c0104a6f>] show_stack+0x7f/0xa0
[<c0104c17>] show_registers+0x157/0x1d0
[<c0104eb5>] die+0x175/0x280
[<c0118bd2>] do_page_fault+0x3b2/0x6f2
[<c01045b3>] error_code+0x2b/0x30
[<c0294ebf>] scsi_try_bus_reset+0xbf/0x370
[<c029555e>] scsi_eh_bus_reset+0x7e/0x130
[<c0295a74>] scsi_eh_ready_devs+0x64/0x90
[<c0295c7a>] scsi_unjam_host+0x13a/0x1d0
[<c0295e2e>] scsi_error_handler+0x11e/0x150
[<c0101355>] kernel_thread_helper+0x5/0x10
Code: 24 04 6b 00 00 00 c7 04 24 56 44 ba d8 e8 2a e2 57 e7 ff 0b 0f 88 3c 05
00 00 8b 43 34 a9
00 00 20 00 0f 85 7b 01 00 00 8b 43 28 <8b> 80 4c 01 00 00 80 78 04 01 0f 84
01 01 00 00 c7 45
f0 f0 ff
I traced the oops down to drivers/usb/storage/scsiglue.c:286
if (test_bit(US_FLIDX_DISCONNECTING, &us->flags)) {
result = -EIO;
US_DEBUGP("No reset during disconnect\n");
} else if (us->pusb_dev->actconfig->desc.bNumInterfaces != 1) {
^^^^^^^^^^^^^^^^^^^^^^^ Oops ^^^^^^^^^^^^^^^^^^^^^^^^^
result = -EBUSY;
US_DEBUGP("Refusing to reset a multi-interface device\n");
} else {
-------------------------------------------------------
SF email is sponsored by - The IT Product Guide
Read honest & candid reviews on hundreds of IT Products from real users.
Discover which products truly live up to the hype. Start reading now.
http://ads.osdn.com/?ad_id=6595&alloc_id=14396&op=click
_______________________________________________
[email protected]
To unsubscribe, use the last form field at:
https://lists.sourceforge.net/lists/listinfo/linux-usb-devel