Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1758763AbZALWpq (ORCPT ); Mon, 12 Jan 2009 17:45:46 -0500 Received: (majordomo@vger.kernel.org) by vger.kernel.org id S1759496AbZALWa3 (ORCPT ); Mon, 12 Jan 2009 17:30:29 -0500 Received: from netrider.rowland.org ([192.131.102.5]:3580 "HELO netrider.rowland.org" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with SMTP id S1758979AbZALWa0 (ORCPT ); Mon, 12 Jan 2009 17:30:26 -0500 Date: Mon, 12 Jan 2009 17:30:25 -0500 (EST) From: Alan Stern X-X-Sender: stern@netrider.rowland.org To: Gabriel C cc: Linux Kernel list , Greg Kroah-Hartman , Subject: Re: [usb-storage]: WARNING: at drivers/usb/storage/transport.c:584 last_sector_hacks+0x11d/0x190() In-Reply-To: <4967B6DD.9050705@googlemail.com> Message-ID: MIME-Version: 1.0 Content-Type: TEXT/PLAIN; charset=US-ASCII Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org Content-Length: 9456 Lines: 167 On Fri, 9 Jan 2009, Gabriel C wrote: > Hallo, > > Since commit 25ff1c316f6a763f1eefe7f8984b2d8c03888432 I get the following trace on my logs: > > .. > > [ 12.352477] usb-storage: device scan complete > [ 12.353583] scsi 6:0:0:0: Direct-Access Ut163 USB2FlashStorage 0.00 PQ: 0 ANSI: 2 > [ 12.360519] sd 6:0:0:0: Attached scsi generic sg4 type 0 > [ 12.361066] sd 6:0:0:0: [sdd] 1974271 512-byte hardware sectors: (1.01 GB/963 MiB) > [ 12.371194] sd 6:0:0:0: [sdd] Write Protect is off > [ 12.376659] sd 6:0:0:0: [sdd] Mode Sense: 00 00 00 00 > [ 12.376661] sd 6:0:0:0: [sdd] Assuming drive cache: write through > [ 12.385072] sd 6:0:0:0: [sdd] 1974271 512-byte hardware sectors: (1.01 GB/963 MiB) > [ 12.391068] sd 6:0:0:0: [sdd] Write Protect is off > [ 12.396175] sd 6:0:0:0: [sdd] Mode Sense: 00 00 00 00 > [ 12.396177] sd 6:0:0:0: [sdd] Assuming drive cache: write through > [ 12.401288] sdd: sdd1 > [ 12.503047] sd 6:0:0:0: [sdd] Attached SCSI removable disk > [ 12.640809] ------------[ cut here ]------------ > [ 12.646035] WARNING: at drivers/usb/storage/transport.c:584 last_sector_hacks+0x11d/0x190() > [ 12.651323] Hardware name: P5E-VM DO > [ 12.656585] sdd: Successful last sector success at 1974270, device 1307:0163:0100 > [ 12.661952] Modules linked in: fuse loop lp ppdev parport_pc joydev parport processor button pcspkr i2c_i801 evdev sg intel_agp > [ 12.673052] Pid: 1194, comm: usb-storage Not tainted 2.6.28-07939-g2150edc #34 > [ 12.678627] Call Trace: > [ 12.684040] [] warn_slowpath+0xd0/0x130 > [ 12.689408] [] ? schedule_timeout+0xb5/0xf0 > [ 12.694635] [] ? sg_clean+0x3e/0x80 > [ 12.699737] [] ? _spin_unlock_irq+0x9/0x50 > [ 12.704714] [] ? wait_for_common+0xfa/0x170 > [ 12.709536] [] ? default_wake_function+0x0/0x10 > [ 12.714366] [] ? usb_stor_msg_common+0x126/0x180 > [ 12.719171] [] ? usb_stor_bulk_transfer_buf+0x8c/0xb0 > [ 12.719174] [] last_sector_hacks+0x11d/0x190 > [ 12.719176] [] usb_stor_invoke_transport+0x1e4/0x390 > [ 12.719178] [] ? _spin_unlock_irq+0x9/0x50 > [ 12.719181] [] ? wait_for_common+0xfa/0x170 > [ 12.719183] [] ? default_wake_function+0x0/0x10 > [ 12.719186] [] usb_stor_transparent_scsi_command+0x9/0x10 > [ 12.719188] [] usb_stor_control_thread+0x13f/0x230 > [ 12.719191] [] ? usb_stor_control_thread+0x0/0x230 > [ 12.719194] [] kthread+0x49/0x90 > [ 12.719196] [] child_rip+0xa/0x20 > [ 12.719199] [] ? kthread+0x0/0x90 > [ 12.719200] [] ? child_rip+0x0/0x20 > [ 12.719202] ---[ end trace 1b5f08c07bcaea59 ]--- > > > .... > > > From the commit log I see this is indeed but personally I think the WARN() is really not needed here > since is spamming the console for no reason. A friendly user message should do it here no ? > > Something like : > > $dev: Successful last sector success at xxxx, device xxxx > $dev: Your device may need an an unusual_devs entry , please contact > > ( Also why don't you guys introduce some CONFIG_KERNELOOPS_ORG_REALLY_SPAM_ME and > let the user or distros which are using kerneloops.org to decide whatever to enable or disable these warnings ? ) The original reasons for adding this WARN() no longer apply, and I plan to remove it before 2.6.29.final. However I do admit to being curious to see from the kerneloops records how often it triggers... > However while trying to add an unusual_devs entry for my device I got the following error message when running lsusb -v -d the_device : > > ... > > can't get device qualifier: Connection timed out > can't get debug descriptor: Connection timed out > cannot read device status, Connection timed out (110) > ... > > And in dmesg : > > ... > > 1317.433117] usb 1-4: usbfs: USBDEVFS_CONTROL failed cmd lsusb rqt 128 rq 6 len 4 ret -110 > [ 1322.433130] usb 1-4: usbfs: USBDEVFS_CONTROL failed cmd lsusb rqt 128 rq 0 len 2 ret -110 > [ 2310.219145] usb 1-4: usbfs: USBDEVFS_CONTROL failed cmd lsusb rqt 128 rq 6 len 255 ret -110 > [ 2311.219149] usb 1-4: usbfs: USBDEVFS_CONTROL failed cmd lsusb rqt 128 rq 6 len 255 ret -110 > [ 2312.219144] usb 1-4: usbfs: USBDEVFS_CONTROL failed cmd lsusb rqt 128 rq 6 len 255 ret -110 > [ 2317.219161] usb 1-4: usbfs: USBDEVFS_CONTROL failed cmd lsusb rqt 128 rq 6 len 10 ret -110 > [ 2322.219047] usb 1-4: usbfs: USBDEVFS_CONTROL failed cmd lsusb rqt 128 rq 6 len 4 ret -110 > [ 2327.219066] usb 1-4: usbfs: USBDEVFS_CONTROL failed cmd lsusb rqt 128 rq 0 len 2 ret -110 > [ 2340.806018] usb 1-4: reset high speed USB device using ehci_hcd and address 2 > [ 2340.920348] usb 1-4: device firmware changed > [ 2340.920368] usb 1-4: USB disconnect, address 2 > [ 2340.920376] sd 6:0:0:0: Device offlined - not ready after error recovery > [ 2341.036024] usb 1-4: new high speed USB device using ehci_hcd and address 3 > [ 2341.153472] usb 1-4: configuration #1 chosen from 1 choice > [ 2341.153730] scsi7 : SCSI emulation for USB Mass Storage devices > [ 2341.153808] usb-storage: device found at 3 > [ 2341.153811] usb-storage: waiting for device to settle before scanning > [ 2346.153159] usb-storage: device scan complete > [ 2346.154269] scsi 7:0:0:0: Direct-Access Ut163 USB2FlashStorage 0.00 PQ: 0 ANSI: 2 > [ 2346.155235] sd 7:0:0:0: Attached scsi generic sg4 type 0 > [ 2346.156002] sd 7:0:0:0: [sdd] 1974271 512-byte hardware sectors: (1.01 GB/963 MiB) > [ 2346.162519] sd 7:0:0:0: [sdd] Write Protect is off > [ 2346.162522] sd 7:0:0:0: [sdd] Mode Sense: 00 00 00 00 > [ 2346.162524] sd 7:0:0:0: [sdd] Assuming drive cache: write through > [ 2346.165502] sd 7:0:0:0: [sdd] 1974271 512-byte hardware sectors: (1.01 GB/963 MiB) > [ 2346.166499] sd 7:0:0:0: [sdd] Write Protect is off > [ 2346.166501] sd 7:0:0:0: [sdd] Mode Sense: 00 00 00 00 > [ 2346.166503] sd 7:0:0:0: [sdd] Assuming drive cache: write through > [ 2346.166506] sdd: sdd1 > [ 2346.268072] sd 7:0:0:0: [sdd] Attached SCSI removable disk > [ 2346.407115] ------------[ cut here ]------------ > [ 2346.407119] WARNING: at drivers/usb/storage/transport.c:584 last_sector_hacks+0x11d/0x190() > [ 2346.407121] Hardware name: P5E-VM DO > [ 2346.407123] sdd: Successful last sector success at 1974270, device 1307:0163:0100 > [ 2346.407124] Modules linked in: i915 binfmt_misc acpi_cpufreq freq_table w83627ehf hwmon_vid fuse loop lp ppdev parport_pc joydev parport processor button pcspkr i2c_i801 evdev sg intel_agp > [ 2346.407187] Pid: 13084, comm: usb-storage Tainted: G W 2.6.28-07939-g2150edc #34 > [ 2346.407195] Call Trace: > [ 2346.407206] [] warn_slowpath+0xd0/0x130 > [ 2346.407216] [] ? schedule_timeout+0xb5/0xf0 > [ 2346.407225] [] ? urb_destroy+0x23/0x30 > [ 2346.407234] [] ? _spin_unlock_irq+0x9/0x50 > [ 2346.407242] [] ? wait_for_common+0xfa/0x170 > [ 2346.407251] [] ? default_wake_function+0x0/0x10 > [ 2346.407260] [] ? usb_stor_msg_common+0x126/0x180 > [ 2346.407269] [] ? usb_stor_bulk_transfer_buf+0x8c/0xb0 > [ 2346.407278] [] last_sector_hacks+0x11d/0x190 > [ 2346.407288] [] usb_stor_invoke_transport+0x1e4/0x390 > [ 2346.407298] [] ? _spin_unlock_irq+0x9/0x50 > [ 2346.407307] [] ? wait_for_common+0xfa/0x170 > [ 2346.407317] [] ? default_wake_function+0x0/0x10 > [ 2346.407326] [] usb_stor_transparent_scsi_command+0x9/0x10 > [ 2346.407336] [] usb_stor_control_thread+0x13f/0x230 > [ 2346.407346] [] ? usb_stor_control_thread+0x0/0x230 > [ 2346.407355] [] kthread+0x49/0x90 > [ 2346.407364] [] child_rip+0xa/0x20 > [ 2346.407373] [] ? kthread+0x0/0x90 > [ 2346.407379] [] ? child_rip+0x0/0x20 > [ 2346.407381] ---[ end trace 1b5f08c07bcaea5a ]--- > [ 2412.896338] FAT: utf8 is not a recommended IO charset for FAT filesystems, filesystem will be case sensitive! > [ 2422.169223] usb 1-4: usbfs: USBDEVFS_CONTROL failed cmd lsusb rqt 128 rq 6 len 4 ret -110 > [ 2427.169483] usb 1-4: usbfs: USBDEVFS_CONTROL failed cmd lsusb rqt 128 rq 0 len 2 ret -110 > > ... > > > This is probably some different bug / feature ? :) It is certainly different. I can't tell the cause from the information in your log. You should try usbmon (see Documentation/usb/usbmon.txt). > Since I get now a bit confused about all this warnings , it is OK to add any entry for that device or it is broken ? The WARN() does not indicate anything wrong with your device. In fact, you can remove the WARN() entirely from your kernel, if you like. Or you can add a local unusual_devs entry. As for the lsusb problem, I don't know. Alan Stern -- To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to majordomo@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/