Messages in this thread | | | Date | Mon, 28 Jul 2008 15:23:21 +0200 | From | Riccardo Magliocchetti <> | Subject | soft lockup while copying data from a FAT usb stick and consequent FAT table corruption |
| |
Hi,
[I'm not subscribed please CC me.]
I got a system lockup while copying some data from an usb stick formatted in FAT, the kernel is a debian 2.6.25-2 which is based on vanilla 2.6.25.11. The stick is a cheap one. This an excerpt from the logs:
Jul 24 19:03:04 eurasia kernel: [25069.980240] usb 1-5: configuration #1 chosen from 1 choice Jul 24 19:03:04 eurasia kernel: [25069.980240] usb 1-5: New USB device found, idVendor=0402, idProduct=5661 Jul 24 19:03:04 eurasia kernel: [25069.980240] usb 1-5: New USB device strings: Mfr=3, Product=1, SerialNumber=2 Jul 24 19:03:04 eurasia kernel: [25069.980240] usb 1-5: Product: Audio Player Jul 24 19:03:04 eurasia kernel: [25069.980240] usb 1-5: Manufacturer: ALi Corp. Jul 24 19:03:04 eurasia kernel: [25069.980240] usb 1-5: SerialNumber: 00101000101410066364 Jul 24 19:03:05 eurasia kernel: [25070.196765] Initializing USB Mass Storage driver... Jul 24 19:03:05 eurasia kernel: [25070.198256] scsi0 : SCSI emulation for USB Mass Storage devices Jul 24 19:03:05 eurasia kernel: [25070.198682] usbcore: registered new interface driver usb-storage Jul 24 19:03:05 eurasia kernel: [25070.198689] USB Mass Storage support registered. Jul 24 19:03:05 eurasia kernel: [25070.206876] usb-storage: device found at 2 Jul 24 19:03:05 eurasia kernel: [25070.206883] usb-storage: waiting for device to settle before scanning Jul 24 19:03:10 eurasia kernel: [25075.519313] usb-storage: device scan complete Jul 24 19:03:10 eurasia kernel: [25075.520143] scsi 0:0:0:0: Direct-Access Audio Player PQ: 0 ANSI: 0 CCS Jul 24 19:03:10 eurasia kernel: [25075.608201] Driver 'sd' needs updating - please use bus_type methods Jul 24 19:03:10 eurasia kernel: [25075.610031] sd 0:0:0:0: [sda] 4073984 512-byte hardware sectors (2086 MB) Jul 24 19:03:10 eurasia kernel: [25075.610886] sd 0:0:0:0: [sda] Write Protect is off Jul 24 19:03:10 eurasia kernel: [25075.610891] sd 0:0:0:0: [sda] Mode Sense: 3b 00 00 00 Jul 24 19:03:10 eurasia kernel: [25075.610893] sd 0:0:0:0: [sda] Assuming drive cache: write through Jul 24 19:03:10 eurasia kernel: [25075.615127] sd 0:0:0:0: [sda] 4073984 512-byte hardware sectors (2086 MB) Jul 24 19:03:10 eurasia kernel: [25075.616142] sd 0:0:0:0: [sda] Write Protect is off Jul 24 19:03:10 eurasia kernel: [25075.616147] sd 0:0:0:0: [sda] Mode Sense: 3b 00 00 00 Jul 24 19:03:10 eurasia kernel: [25075.616150] sd 0:0:0:0: [sda] Assuming drive cache: write through Jul 24 19:03:10 eurasia kernel: [25075.616153] sda: sda1 Jul 24 19:03:10 eurasia kernel: [25075.617510] sd 0:0:0:0: [sda] Attached SCSI removable disk Jul 24 19:03:17 eurasia kernel: [25083.820927] usb 1-5: reset high speed USB device using ehci_hcd and address 2 Jul 24 19:03:19 eurasia kernel: [25085.483682] usb 1-5: reset high speed USB device using ehci_hcd and address 2 Jul 24 19:03:19 eurasia kernel: [25085.624466] sd 0:0:0:0: [sda] Result: hostbyte=DID_ERROR driverbyte=DRIVER_OK,SUGGEST_OK Jul 24 19:03:19 eurasia kernel: [25085.624466] end_request: I/O error, dev sda, sector 37 Jul 24 19:03:26 eurasia kernel: [25093.125099] usb 1-5: reset high speed USB device using ehci_hcd and address 2 Jul 24 19:03:30 eurasia kernel: [25097.113851] usb 1-5: reset high speed USB device using ehci_hcd and address 2 Jul 24 19:03:30 eurasia kernel: [25097.576447] usb 1-5: reset high speed USB device using ehci_hcd and address 2 Jul 24 19:03:31 eurasia kernel: [25098.410646] usb 1-5: reset high speed USB device using ehci_hcd and address 2 Jul 24 19:03:32 eurasia kernel: [25099.269510] usb 1-5: reset high speed USB device using ehci_hcd and address 2 Jul 24 19:03:33 eurasia kernel: [25100.769788] usb 1-5: reset high speed USB device using ehci_hcd and address 2 Jul 24 19:03:34 eurasia kernel: [25101.468735] usb 1-5: reset high speed USB device using ehci_hcd and address 2 Jul 24 19:03:35 eurasia kernel: [25102.535667] usb 1-5: reset high speed USB device using ehci_hcd and address 2 Jul 24 19:03:35 eurasia kernel: [25102.849478] usb 1-5: reset high speed USB device using ehci_hcd and address 2 Jul 24 19:03:36 eurasia kernel: [25103.152891] usb 1-5: reset high speed USB device using ehci_hcd and address 2 Jul 24 19:03:48 eurasia kernel: [25115.838545] usb 1-5: reset high speed USB device using ehci_hcd and address 2 Jul 24 19:03:48 eurasia kernel: [25116.112641] usb 1-5: reset high speed USB device using ehci_hcd and address 2 Jul 24 19:03:48 eurasia kernel: [25116.407009] usb 1-5: reset high speed USB device using ehci_hcd and address 2 Jul 24 19:03:59 eurasia kernel: [25127.511585] usb 1-5: reset high speed USB device using ehci_hcd and address 2 Jul 24 19:04:05 eurasia kernel: [25133.857934] usb 1-5: reset high speed USB device using ehci_hcd and address 2 Jul 24 19:04:05 eurasia kernel: [25134.138299] usb 1-5: reset high speed USB device using ehci_hcd and address 2 Jul 24 19:04:05 eurasia kernel: [25134.280260] usb 1-5: can't restore configuration #1 (error=-71) Jul 24 19:04:05 eurasia kernel: [25134.280289] usb 1-5: USB disconnect, address 2 Jul 24 19:04:05 eurasia kernel: [25134.280291] sd 0:0:0:0: [sda] Result: hostbyte=DID_ERROR driverbyte=DRIVER_OK,SUGGEST_OK Jul 24 19:04:05 eurasia kernel: [25134.280291] end_request: I/O error, dev sda, sector 1018212 Jul 24 19:04:05 eurasia kernel: [25134.280291] sd 0:0:0:0: [sda] Result: hostbyte=DID_ERROR driverbyte=DRIVER_OK,SUGGEST_OK Jul 24 19:04:05 eurasia kernel: [25134.280291] end_request: I/O error, dev sda, sector 1018452 Jul 24 19:04:05 eurasia kernel: [25134.280292] sd 0:0:0:0: [sda] Result: hostbyte=DID_ERROR driverbyte=DRIVER_OK,SUGGEST_OK Jul 24 19:04:05 eurasia kernel: [25134.280292] end_request: I/O error, dev sda, sector 1018484 Jul 24 19:04:05 eurasia kernel: [25134.280292] sd 0:0:0:0: [sda] Result: hostbyte=DID_ERROR driverbyte=DRIVER_OK,SUGGEST_OK Jul 24 19:04:05 eurasia kernel: [25134.280292] end_request: I/O error, dev sda, sector 1018724 Jul 24 19:04:05 eurasia kernel: [25134.280292] sd 0:0:0:0: [sda] Result: hostbyte=DID_ERROR driverbyte=DRIVER_OK,SUGGEST_OK Jul 24 19:04:05 eurasia kernel: [25134.280292] end_request: I/O error, dev sda, sector 1018964 Jul 24 19:04:05 eurasia kernel: [25134.280292] sd 0:0:0:0: [sda] Result: hostbyte=DID_ERROR driverbyte=DRIVER_OK,SUGGEST_OK Jul 24 19:04:05 eurasia kernel: [25134.280292] end_request: I/O error, dev sda, sector 1018212 Jul 24 19:04:05 eurasia kernel: [25134.280708] Buffer I/O error on device sda1, logical block 500 Jul 24 19:04:05 eurasia kernel: [25134.280716] lost page write due to I/O error on sda1 Jul 24 19:04:05 eurasia kernel: [25134.280720] Buffer I/O error on device sda1, logical block 501 Jul 24 19:04:05 eurasia kernel: [25134.280723] lost page write due to I/O error on sda1 Jul 24 19:04:05 eurasia kernel: [25134.280726] Buffer I/O error on device sda1, logical block 502 Jul 24 19:04:05 eurasia kernel: [25134.280729] lost page write due to I/O error on sda1 Jul 24 19:04:05 eurasia kernel: [25134.280732] Buffer I/O error on device sda1, logical block 503 Jul 24 19:04:05 eurasia kernel: [25134.280734] lost page write due to I/O error on sda1 Jul 24 19:04:05 eurasia kernel: [25134.280739] Buffer I/O error on device sda1, logical block 504 Jul 24 19:04:05 eurasia kernel: [25134.280742] lost page write due to I/O error on sda1 Jul 24 19:04:05 eurasia kernel: [25134.280745] Buffer I/O error on device sda1, logical block 505 Jul 24 19:04:05 eurasia kernel: [25134.280748] lost page write due to I/O error on sda1 Jul 24 19:04:05 eurasia kernel: [25134.280755] Buffer I/O error on device sda1, logical block 507 Jul 24 19:04:05 eurasia kernel: [25134.280758] lost page write due to I/O error on sda1 Jul 24 19:04:05 eurasia kernel: [25134.280761] Buffer I/O error on device sda1, logical block 508 Jul 24 19:04:05 eurasia kernel: [25134.280763] lost page write due to I/O error on sda1 Jul 24 19:04:05 eurasia kernel: [25134.280766] Buffer I/O error on device sda1, logical block 509 Jul 24 19:04:05 eurasia kernel: [25134.280769] lost page write due to I/O error on sda1 Jul 24 19:04:05 eurasia kernel: [25134.280773] Buffer I/O error on device sda1, logical block 512 Jul 24 19:04:05 eurasia kernel: [25134.280775] lost page write due to I/O error on sda1 Jul 24 19:04:05 eurasia kernel: [25134.396333] usb 1-5: new high speed USB device using ehci_hcd and address 3 Jul 24 19:04:05 eurasia kernel: [25134.530771] usb 1-5: configuration #1 chosen from 1 choice Jul 24 19:04:05 eurasia kernel: [25134.537483] scsi1 : SCSI emulation for USB Mass Storage devices Jul 24 19:04:05 eurasia kernel: [25134.541818] usb 1-5: New USB device found, idVendor=0402, idProduct=5661 Jul 24 19:04:05 eurasia kernel: [25134.541826] usb 1-5: New USB device strings: Mfr=3, Product=1, SerialNumber=2 Jul 24 19:04:05 eurasia kernel: [25134.541829] usb 1-5: Product: Audio Player Jul 24 19:04:05 eurasia kernel: [25134.541831] usb 1-5: Manufacturer: ALi Corp. Jul 24 19:04:05 eurasia kernel: [25134.541833] usb 1-5: SerialNumber: 00101000101410066364 Jul 24 19:04:05 eurasia kernel: [25134.542383] usb-storage: device found at 3 Jul 24 19:04:05 eurasia kernel: [25134.542388] usb-storage: waiting for device to settle before scanning Jul 24 19:04:05 eurasia kernel: 34.580436] FAT: Directory bread(block 501) failed Jul 24 19:04:05 eurasia kernel: [25134.580443] FAT: Directory bread(block 502) failed Jul 24 19:04:05 eurasia kernel: [25134.580451] FAT: Directory bread(block 503) failed Jul 24 19:04:05 eurasia kernel: [25134.580461] FAT: Directory bread(block 504) failed Jul 24 19:04:05 eurasia kernel: [25134.580468] FAT: Directory bread(block 505) failed Jul 24 19:04:05 eurasia kernel: [25134.580475] FAT: Directory bread(block 506) failed Jul 24 19:04:05 eurasia kernel: [25134.580482] FAT: Directory bread(block 507) failed Jul 24 19:04:05 eurasia kernel: [25134.580489] FAT: Directory bread(block 508) failed Jul 24 19:04:05 eurasia kernel: [25134.580495] FAT: Directory bread(block 509) failed Jul 24 19:04:05 eurasia kernel: [25134.580502] FAT: Directory bread(block 510) failed Jul 24 19:04:05 eurasia kernel: [25134.580508] FAT: Directory bread(block 511) failed Jul 24 19:04:05 eurasia kernel: [25134.580518] FAT: Directory bread(block 512) failed Jul 24 19:04:05 eurasia kernel: [25134.580525] FAT: Directory bread(block 513) failed Jul 24 19:04:05 eurasia kernel: [25134.580531] FAT: Directory bread(block 514) failed Jul 24 19:04:05 eurasia kernel: [25134.580538] FAT: Directory bread(block 515) failed Jul 24 19:04:05 eurasia kernel: [25134.580544] FAT: Directory bread(block 516) failed Jul 24 19:04:05 eurasia kernel: [25134.580551] FAT: Directory bread(block 517) failed Jul 24 19:04:05 eurasia kernel: [25134.580557] FAT: Directory bread(block 518) failed Jul 24 19:04:05 eurasia kernel: [25134.580564] FAT: Directory bread(block 519) failed Jul 24 19:04:05 eurasia kernel: [25134.580573] FAT: Directory bread(block 520) failed Jul 24 19:04:05 eurasia kernel: [25134.580580] FAT: Directory bread(block 521) failed Jul 24 19:04:05 eurasia kernel: [25134.580587] FAT: Directory bread(block 522) failed Jul 24 19:04:05 eurasia kernel: [25134.580593] FAT: Directory bread(block 523) failed Jul 24 19:04:05 eurasia kernel: [25134.580600] FAT: Directory bread(block 524) failed Jul 24 19:04:05 eurasia kernel: [25134.580607] FAT: Directory bread(block 525) failed Jul 24 19:04:05 eurasia kernel: [25134.580613] FAT: Directory bread(block 526) failed Jul 24 19:04:05 eurasia kernel: [25134.580620] FAT: Directory bread(block 527) failed Jul 24 19:04:05 eurasia kernel: [25134.580634] FAT: Directory bread(block 528) failed Jul 24 19:04:05 eurasia kernel: [25134.580641] FAT: Directory bread(block 529) failed Jul 24 19:04:05 eurasia kernel: [25134.580648] FAT: Directory bread(block 530) failed Jul 24 19:04:05 eurasia kernel: [25134.580655] FAT: Directory bread(block 531) failed
[this stuff is repeated n times]
i managed to get a syrq + p:
Jul 24 19:08:33 eurasia kernel: [25412.247908] Pid: 32692, comm: Thunar Not tainted (2.6.25-2-686 #1) Jul 24 19:08:33 eurasia kernel: [25412.247908] EIP: 0060:[<f88e38e8>] EFLAGS: 00200206 CPU: 0 Jul 24 19:08:33 eurasia kernel: [25412.247908] EIP is at scsi_request_fn+0x2d3/0x322 [scsi_mod] Jul 24 19:08:33 eurasia kernel: [25412.247908] EAX: f7840a00 EBX: 00000000 ECX: c034fe68 EDX: 00000000 Jul 24 19:08:33 eurasia kernel: [25412.247908] ESI: f6220800 EDI: e2631400 EBP: f78408c8 ESP: f6277abc Jul 24 19:08:33 eurasia kernel: [25412.247908] DS: 007b ES: 007b FS: 00d8 GS: 0033 SS: 0068 Jul 24 19:08:33 eurasia kernel: [25412.247908] CR0: 8005003b CR2: 080aeca8 CR3: 367b9000 CR4: 000006d0 Jul 24 19:08:33 eurasia kernel: [25412.247908] DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000 Jul 24 19:08:33 eurasia kernel: [25412.247908] DR6: ffff0ff0 DR7: 00000400 Jul 24 19:08:33 eurasia kernel: [25412.247908] [<c01d197d>] ? __generic_unplug_device+0x1a/0x1c Jul 24 19:08:33 eurasia kernel: [25412.247908] [<c01cf884>] ? elv_insert+0x10f/0x1a5 Jul 24 19:08:33 eurasia kernel: [25412.247908] [<c01d219a>] ? __make_request+0x2fe/0x348 Jul 24 19:08:33 eurasia kernel: [25412.247908] [<c0197121>] ? do_mpage_readpage+0x4f8/0x5bb Jul 24 19:08:33 eurasia kernel: [25412.247908] [<c01d0e56>] ? generic_make_request+0x34d/0x37b Jul 24 19:08:33 eurasia kernel: [25412.247908] [<c011309e>] ? lapic_next_event+0xc/0x10 Jul 24 19:08:33 eurasia kernel: [25412.247908] [<c013a254>] ? clockevents_program_event+0xc4/0xd2 Jul 24 19:08:33 eurasia kernel: [25412.247908] [<c01d1e95>] ? submit_bio+0xc6/0xcd Jul 24 19:08:33 eurasia kernel: [25412.247908] [<c0197237>] ? mpage_end_io_read+0x0/0x53 Jul 24 19:08:33 eurasia kernel: [25412.247908] [<c0196566>] ? mpage_bio_submit+0x19/0x1d Jul 24 19:08:33 eurasia kernel: [25412.247908] [<c0197231>] ? mpage_readpage+0x4d/0x53 Jul 24 19:08:33 eurasia kernel: [25412.247908] [<c0108314>] ? apic_timer_interrupt+0x28/0x30 Jul 24 19:08:33 eurasia kernel: [25412.247908] [<c0158705>] ? find_lock_page+0x19/0x7f Jul 24 19:08:33 eurasia kernel: [25412.247908] [<c015a6f9>] ? filemap_fault+0x315/0x36d Jul 24 19:08:33 eurasia kernel: [25412.247908] [<c0190899>] ? __find_get_block+0x176/0x180 Jul 24 19:08:33 eurasia kernel: [25412.247908] [<c0163360>] ? __do_fault+0x59/0x38e Jul 24 19:08:33 eurasia kernel: [25412.247908] [<c01908ca>] ? __getblk+0x27/0x254 Jul 24 19:08:33 eurasia kernel: [25412.247908] [<c01654e2>] ? handle_mm_fault+0x2c5/0x6bb Jul 24 19:08:33 eurasia kernel: [25412.247908] [<f894c55d>] ? __ext3_get_inode_loc+0x109/0x2b6 [ext3] Jul 24 19:08:33 eurasia kernel: [25412.247908] [<f894c3ee>] ? ext3_mark_iloc_dirty+0x279/0x2df [ext3] Jul 24 19:08:33 eurasia kernel: [25412.247908] [<c011cc1b>] ? __wake_up+0x29/0x39 Jul 24 19:08:33 eurasia kernel: [25412.247908] [<c0118b4c>] ? do_page_fault+0x268/0x584 Jul 24 19:08:33 eurasia kernel: [25412.247908] [<f89532ba>] ? __ext3_journal_stop+0x19/0x34 [ext3] Jul 24 19:08:33 eurasia kernel: [25412.247908] [<c01188e4>] ? do_page_fault+0x0/0x584 Jul 24 19:08:33 eurasia kernel: [25412.247908] [<c02b579a>] ? error_code+0x72/0x78 Jul 24 19:08:33 eurasia kernel: [25412.247908] [<c0157d9c>] ? iov_iter_fault_in_readable+0x20/0x53 Jul 24 19:08:33 eurasia kernel: [25412.247908] [<c01592cd>] ? generic_file_buffered_write+0xc7/0x553 Jul 24 19:08:33 eurasia kernel: [25412.247908] [<f8959781>] ? ext3_xattr_security_get+0x31/0x3b [ext3] Jul 24 19:08:33 eurasia kernel: [25412.247908] [<c018b1f0>] ? generic_getxattr+0x0/0x3d Jul 24 19:08:33 eurasia kernel: [25412.247908] [<c0159bbd>] ? __generic_file_aio_write_nolock+0x464/0x4c6 Jul 24 19:08:33 eurasia kernel: [25412.247908] [<c0198483>] ? inotify_dev_queue_event+0xf8/0x109 Jul 24 19:08:33 eurasia kernel: [25412.247908] [<c0197a34>] ? inotify_inode_queue_event+0x9a/0xc6 Jul 24 19:08:33 eurasia kernel: [25412.247908] [<c0159c71>] ? generic_file_aio_write+0x52/0xa9 Jul 24 19:08:33 eurasia kernel: [25412.247908] [<f894af8d>] ? ext3_file_write+0x19/0x83 [ext3] Jul 24 19:08:33 eurasia kernel: [25412.247908] [<c0175752>] ? do_sync_write+0xbf/0x100 Jul 24 19:08:33 eurasia kernel: [25412.247908] [<c01339f0>] ? autoremove_wake_function+0x0/0x2d Jul 24 19:08:33 eurasia kernel: [25412.247908] [<c01b91a8>] ? security_file_permission+0xc/0xd Jul 24 19:08:33 eurasia kernel: [25412.247908] [<c0175693>] ? do_sync_write+0x0/0x100 Jul 24 19:08:33 eurasia kernel: [25412.247908] [<c0175ebc>] ? vfs_write+0x83/0x120 Jul 24 19:08:33 eurasia kernel: [25412.247908] [<c0176488>] ? sys_write+0x3c/0x63 Jul 24 19:08:33 eurasia kernel: [25412.247908] [<c0107862>] ? syscall_call+0x7/0xb
Attached you'll find compressed my config and the full syslog stuff.
I have the log of a file recovery tool for windows called testdisk [1] if you find them useful.
This is the relevant fstab line:
/dev/sda1 /media/usb auto noauto,user,rw,async 0 0
thanks, Riccardo
[1] http://www.cgsecurity.org/wiki/TestDisk [unhandled content-type:application/x-compressed-tar][unhandled content-type:application/x-compressed-tar] | |