Public bug reported:
An embedded system, comprising COM Express module and USB SSD with
Ubuntu Linux Server 10.04 (Lucid Lynx), hangs after certain period of
activity. Period between the hangs varies from two days to one week.
Symptoms of the hang:
* machine is unreachable over ssh
* machine is pingable
* file system appears to be empty for SSH sessions started before the hang (ls
doesn't list anything, unable to start any command)
This issue was not present when using Ubuntu Linux 8.04.
In order to get details about the hang, Ubuntu Linux kernel was compiled
with additional options:
CONFIG_USB_STORAGE_DEBUG=y
CONFIG_USB=y
CONFIG_USB_DEBUG=y
In addition to that, netconsole module was used to redirect syslog to
another machine to be able to analyse it.
It seems that the problem happens in the following lines and causes ext3
to OOPS a bit later:
Jan 10 10:41:15 hudson-slave [262388.606612] usb-storage:
usb_stor_bulk_transfer_buf: xfer 31 bytes
Jan 10 10:41:24 hudson-slave [262397.557075] hub 1-0:1.0: state 7 ports 8 chg
0000 evt 0040
Jan 10 10:41:24 hudson-slave [262397.558208] ehci_hcd 0000:00:1d.7: GetStatus
port 6 status 001002 POWER sig=se0 CSC
Jan 10 10:41:24 hudson-slave [262397.559358] hub 1-0:1.0: port 6, status 0100,
change 0001, 12 Mb/s
Jan 10 10:41:24 hudson-slave [262397.560489] usb 1-6: USB disconnect, address 6
Jan 10 10:41:24 hudson-slave [262397.561671] usb 1-6: unregistering device
Jan 10 10:41:24 hudson-slave [262397.562805] usb 1-6: usb_disable_device nuking
all URBs
Jan 10 10:41:24 hudson-slave [262397.563983] ehci_hcd 0000:00:1d.7: shutdown
urb f27f4100 ep2out-bulk
Jan 10 10:41:24 hudson-slave [262397.566277] usb 1-6: unregistering interface
1-6:1.0
Jan 10 10:41:24 hudson-slave [262397.566321] usb-storage: Status code -108;
transferred 31/31
Jan 10 10:41:24 hudson-slave [262397.566325] usb-storage: -- unknown error
Jan 10 10:41:24 hudson-slave [262397.566329] usb-storage: Bulk command transfer
result=4
Jan 10 10:41:24 hudson-slave [262397.566332] usb-storage: -- transport
indicates error, resetting
...
Jan 10 10:41:26 hudson-slave [262397.572511] Buffer I/O error on device sda6,
logical block 0
Jan 10 10:41:26 hudson-slave [262397.572515] lost page write due to I/O error
on sda6
Jan 10 10:41:26 hudson-slave [262397.584278] usb-storage: queuecommand called
Jan 10 10:41:26 hudson-slave [262397.584297] usb-storage: *** thread awakened.
Jan 10 10:41:26 hudson-slave [262397.584301] usb-storage: Command WRITE_10 (10
bytes)
Jan 10 10:41:26 hudson-slave [262397.584303] usb-storage: 2a 00 00 38 e1 e8 00
00 10 00
Jan 10 10:41:26 hudson-slave [262397.584316] usb-storage: Bulk Command S
0x43425355 T 0x4cb0d L 8192 F 0 Trg 0 LUN 0 CL 10
Jan 10 10:41:26 hudson-slave [262397.584320] usb-storage:
usb_stor_bulk_transfer_buf: xfer 31 bytes
Jan 10 10:41:26 hudson-slave [262397.584325] usb-storage: Status code -19;
transferred 0/31
Jan 10 10:41:26 hudson-slave [262397.584328] usb-storage: -- unknown error
Jan 10 10:41:26 hudson-slave [262397.584330] usb-storage: Bulk command transfer
result=4
Jan 10 10:41:26 hudson-slave [262397.584333] usb-storage: -- transport
indicates error, resetting
Jan 10 10:41:26 hudson-slave [262397.584336] usb-storage: unable to lock device
for reset: -19
Jan 10 10:41:26 hudson-slave [262397.584340] usb-storage: usb_stor_Bulk_reset
called
Jan 10 10:41:26 hudson-slave [262397.584344] usb-storage: usb_stor_control_msg:
rq=ff rqtype=21 value=0000 index=00 len=0
Jan 10 10:41:26 hudson-slave [262397.584348] usb-storage: Soft reset failed:
-19
Jan 10 10:41:26 hudson-slave [262397.584351] usb-storage: scsi cmd done,
result=0x70000
Jan 10 10:41:26 hudson-slave [262397.584356] usb-storage: *** thread sleeping.
Jan 10 10:41:26 hudson-slave [262397.584364] usb-storage: queuecommand called
Jan 10 10:41:26 hudson-slave [262397.584372] usb-storage: *** thread awakened.
Jan 10 10:41:26 hudson-slave [262397.584375] usb-storage: Command WRITE_10 (10
bytes)
Jan 10 10:41:26 hudson-slave [262397.584377] usb-storage: 2a 00 00 38 e1 e8 00
00 10 00
Jan 10 10:41:26 hudson-slave [262397.584389] usb-storage: Bulk Command S
0x43425355 T 0x4cb0e L 8192 F 0 Trg 0 LUN 0 CL 10
Jan 10 10:41:26 hudson-slave [262397.584393] usb-storage:
usb_stor_bulk_transfer_buf: xfer 31 bytes
Jan 10 10:41:26 hudson-slave [262397.584397] usb-storage: Status code -19;
transferred 0/31
Jan 10 10:41:26 hudson-slave [262397.584399] usb-storage: -- unknown error
Jan 10 10:41:26 hudson-slave [262397.584402] usb-storage: Bulk command transfer
result=4
Jan 10 10:41:26 hudson-slave [262397.584405] usb-storage: -- transport
indicates error, resetting
Jan 10 10:41:26 hudson-slave [262397.584408] usb-storage: unable to lock device
for reset: -19
Jan 10 10:41:26 hudson-slave [262397.584411] usb-storage: usb_stor_Bulk_reset
called
Jan 10 10:41:26 hudson-slave [262397.584415] usb-storage: usb_stor_control_msg:
rq=ff rqtype=21 value=0000 index=00 len=0
Jan 10 10:41:26 hudson-slave [262397.584419] usb-storage: Soft reset failed:
-19
Jan 10 10:41:26 hudson-slave [262397.584422] usb-storage: scsi cmd done,
result=0x70000
Jan 10 10:41:26 hudson-slave [262397.584427] usb-storage: *** thread sleeping.
Jan 10 10:41:26 hudson-slave [262397.584434] usb-storage: queuecommand called
Jan 10 10:41:26 hudson-slave [262397.584441] usb-storage: *** thread awakened.
Jan 10 10:41:26 hudson-slave [262397.584444] usb-storage: Command WRITE_10 (10
bytes)
Jan 10 10:41:26 hudson-slave [262397.584447] usb-storage: 2a 00 00 38 e1 e8 00
00 10 00
Jan 10 10:41:26 hudson-slave [262397.584458] usb-storage: Bulk Command S
0x43425355 T 0x4cb0f L 8192 F 0 Trg 0 LUN 0 CL 10
Jan 10 10:41:26 hudson-slave [262397.584463] usb-storage:
usb_stor_bulk_transfer_buf: xfer 31 bytes
Jan 10 10:41:26 hudson-slave [262397.584467] usb-storage: Status code -19;
transferred 0/31
Jan 10 10:41:26 hudson-slave [262397.584469] usb-storage: -- unknown error
Jan 10 10:41:26 hudson-slave [262397.584472] usb-storage: Bulk command transfer
result=4
Jan 10 10:41:26 hudson-slave [262397.584475] usb-storage: -- transport
indicates error, resetting
Jan 10 10:41:26 hudson-slave [262397.584478] usb-storage: unable to lock device
for reset: -19
Jan 10 10:41:26 hudson-slave [262397.584482] usb-storage: usb_stor_Bulk_reset
called
Jan 10 10:41:26 hudson-slave [262397.584486] usb-storage: usb_stor_control_msg:
rq=ff rqtype=21 value=0000 index=00 len=0
Jan 10 10:41:26 hudson-slave [262397.584489] usb-storage: Soft reset failed:
-19
Jan 10 10:41:26 hudson-slave [262397.584492] usb-storage: scsi cmd done,
result=0x70000
Jan 10 10:41:26 hudson-slave [262397.584497] usb-storage: *** thread sleeping.
Jan 10 10:41:26 hudson-slave [262397.584504] usb-storage: queuecommand called
Jan 10 10:41:26 hudson-slave [262397.584510] usb-storage: *** thread awakened.
Jan 10 10:41:26 hudson-slave [262397.584514] usb-storage: Command WRITE_10 (10
bytes)
Jan 10 10:41:26 hudson-slave [262397.584516] usb-storage: 2a 00 00 38 e1 e8 00
00 10 00
Jan 10 10:41:26 hudson-slave [262397.584528] usb-storage: Bulk Command S
0x43425355 T 0x4cb10 L 8192 F 0 Trg 0 LUN 0 CL 10
Jan 10 10:41:26 hudson-slave [262397.584532] usb-storage:
usb_stor_bulk_transfer_buf: xfer 31 bytes
Jan 10 10:41:26 hudson-slave [262397.584536] usb-storage: Status code -19;
transferred 0/31
Jan 10 10:41:26 hudson-slave [262397.584539] usb-storage: -- unknown error
Jan 10 10:41:26 hudson-slave [262397.584541] usb-storage: Bulk command transfer
result=4
Jan 10 10:41:26 hudson-slave [262397.584544] usb-storage: -- transport
indicates error, resetting
Jan 10 10:41:26 hudson-slave [262397.584547] usb-storage: unable to lock device
for reset: -19
Jan 10 10:41:26 hudson-slave [262397.584551] usb-storage: usb_stor_Bulk_reset
called
Jan 10 10:41:26 hudson-slave [262397.584555] usb-storage: usb_stor_control_msg:
rq=ff rqtype=21 value=0000 index=00 len=0
Jan 10 10:41:26 hudson-slave [262397.584558] usb-storage: Soft reset failed:
-19
Jan 10 10:41:26 hudson-slave [262397.584561] usb-storage: scsi cmd done,
result=0x70000
Jan 10 10:41:26 hudson-slave [262397.584566] usb-storage: *** thread sleeping.
Jan 10 10:41:26 hudson-slave [262397.584572] usb-storage: queuecommand called
Jan 10 10:41:26 hudson-slave [262397.584579] usb-storage: *** thread awakened.
Jan 10 10:41:26 hudson-slave [262397.584582] usb-storage: Command WRITE_10 (10
bytes)
Jan 10 10:41:26 hudson-slave [262397.584585] usb-storage: 2a 00 00 38 e1 e8 00
00 10 00
Jan 10 10:41:26 hudson-slave [262397.584597] usb-storage: Bulk Command S
0x43425355 T 0x4cb11 L 8192 F 0 Trg 0 LUN 0 CL 10
Jan 10 10:41:26 hudson-slave [262397.584601] usb-storage:
usb_stor_bulk_transfer_buf: xfer 31 bytes
Jan 10 10:41:26 hudson-slave [262397.584605] usb-storage: Status code -19;
transferred 0/31
Jan 10 10:41:26 hudson-slave [262397.584608] usb-storage: -- unknown error
Jan 10 10:41:26 hudson-slave [262397.584611] usb-storage: Bulk command transfer
result=4
Jan 10 10:41:26 hudson-slave [262397.584613] usb-storage: -- transport
indicates error, resetting
Jan 10 10:41:26 hudson-slave [262397.584617] usb-storage: unable to lock device
for reset: -19
Jan 10 10:41:26 hudson-slave [262397.584620] usb-storage: usb_stor_Bulk_reset
called
Jan 10 10:41:26 hudson-slave [262397.584625] usb-storage: usb_stor_control_msg:
rq=ff rqtype=21 value=0000 index=00 len=0
Jan 10 10:41:26 hudson-slave [262397.584628] usb-storage: Soft reset failed:
-19
Jan 10 10:41:26 hudson-slave [262397.584631] usb-storage: scsi cmd done,
result=0x70000
Jan 10 10:41:26 hudson-slave [262397.584636] usb-storage: *** thread sleeping.
Jan 10 10:41:26 hudson-slave [262397.584642] usb-storage: queuecommand called
Jan 10 10:41:26 hudson-slave [262397.584649] usb-storage: *** thread awakened.
Jan 10 10:41:26 hudson-slave [262397.584652] usb-storage: Command WRITE_10 (10
bytes)
Jan 10 10:41:26 hudson-slave [262397.584655] usb-storage: 2a 00 00 38 e1 e8 00
00 10 00
Jan 10 10:41:26 hudson-slave [262397.584666] usb-storage: Bulk Command S
0x43425355 T 0x4cb12 L 8192 F 0 Trg 0 LUN 0 CL 10
Jan 10 10:41:26 hudson-slave [262397.584670] usb-storage:
usb_stor_bulk_transfer_buf: xfer 31 bytes
Jan 10 10:41:26 hudson-slave [262397.584675] usb-storage: Status code -19;
transferred 0/31
Jan 10 10:41:26 hudson-slave [262397.584677] usb-storage: -- unknown error
Jan 10 10:41:26 hudson-slave [262397.584680] usb-storage: Bulk command transfer
result=4
Jan 10 10:41:26 hudson-slave [262397.584683] usb-storage: -- transport
indicates error, resetting
Jan 10 10:41:26 hudson-slave [262397.584686] usb-storage: unable to lock device
for reset: -19
Jan 10 10:41:26 hudson-slave [262397.584689] usb-storage: usb_stor_Bulk_reset
called
Jan 10 10:41:26 hudson-slave [262397.584694] usb-storage: usb_stor_control_msg:
rq=ff rqtype=21 value=0000 index=00 len=0
Jan 10 10:41:26 hudson-slave [262397.584698] usb-storage: Soft reset failed:
-19
Jan 10 10:41:26 hudson-slave [262397.584701] usb-storage: scsi cmd done,
result=0x70000
Jan 10 10:41:26 hudson-slave [262397.584706] usb-storage: *** thread sleeping.
Jan 10 10:41:26 hudson-slave [262397.584714] sd 2:0:0:0: [sda] Unhandled error
code
Jan 10 10:41:26 hudson-slave [262397.584718] sd 2:0:0:0: [sda] Result:
hostbyte=DID_ERROR driverbyte=DRIVER_OK
Jan 10 10:41:26 hudson-slave [262397.584723] sd 2:0:0:0: [sda] CDB: Write(10):
2a 00 00 38 e1 e8 00 00 10 00
Jan 10 10:41:26 hudson-slave [262397.584735] end_request: I/O error, dev sda,
sector 3727848
Jan 10 10:41:26 hudson-slave [262397.584757] Aborting journal on device sda6.
Jan 10 10:41:26 hudson-slave [262397.584775] usb-storage: queuecommand called
Jan 10 10:41:26 hudson-slave [262397.584788] EXT3-fs error (device sda6) in
ext3_reserve_inode_write: Journal has aborted
Jan 10 10:41:26 hudson-slave [262397.584794] ------------[ cut here
]------------
Jan 10 10:41:26 hudson-slave [262397.584806] WARNING: at
/devel/linux-ubuntu-lucid/fs/buffer.c:1159 mark_buffer_dirty+0x70/0x90()
Jan 10 10:41:26 hudson-slave [262397.584810] Modules linked in: libera fbcon
tileblit font bitblit softcursor vga16fb vgastate netconsole configfs coretemp
lp parport i915 drm_kms_helper drm i2c_algo_bit video serio_raw output
snd_intel8x0 snd_ac97_codec ac97_bus snd_pcm snd_timer snd soundcore
snd_page_alloc intel_agp agpgart usbhid hid usb_storage e1000e r8169 mii
Jan 10 10:41:26 hudson-slave [262397.584858] Pid: 892, comm: rsyslogd Not
tainted 2.6.32-26-generic-pae #47
Jan 10 10:41:26 hudson-slave [262397.584861] Call Trace:
Jan 10 10:41:26 hudson-slave [262397.584871] [<c01543f2>]
warn_slowpath_common+0x72/0xa0
Jan 10 10:41:26 hudson-slave [262397.584877] [<c0237140>] ?
mark_buffer_dirty+0x70/0x90
Jan 10 10:41:26 hudson-slave [262397.584883] [<c0237140>] ?
mark_buffer_dirty+0x70/0x90
Jan 10 10:41:26 hudson-slave [262397.584889] [<c015443a>]
warn_slowpath_null+0x1a/0x20
Jan 10 10:41:26 hudson-slave [262397.584894] [<c0237140>]
mark_buffer_dirty+0x70/0x90
Jan 10 10:41:26 hudson-slave [262397.584900] [<c027a6fa>] T.1021+0x4a/0x70
Jan 10 10:41:26 hudson-slave [262397.584906] [<c027a78b>]
ext3_handle_error+0x6b/0xb0
Jan 10 10:41:26 hudson-slave [262397.584913] [<c05b9ebf>] ? printk+0x1d/0x26
Jan 10 10:41:26 hudson-slave [262397.584918] [<c027a852>]
__ext3_std_error+0x82/0x90
Jan 10 10:41:26 hudson-slave [262397.584925] [<c027f210>] ?
__ext3_journal_get_write_access+0x40/0x50
Jan 10 10:41:26 hudson-slave [262397.584932] [<c0272382>]
ext3_reserve_inode_write+0x42/0x90
Jan 10 10:41:26 hudson-slave [262397.584937] [<c02723fb>]
ext3_mark_inode_dirty+0x2b/0x50
Jan 10 10:41:26 hudson-slave [262397.584943] [<c027254e>]
ext3_dirty_inode+0x4e/0x80
Jan 10 10:41:26 hudson-slave [262397.584950] [<c02fe85e>] ?
cap_inode_need_killpriv+0x2e/0x40
Jan 10 10:41:26 hudson-slave [262397.584957] [<c0231351>]
__mark_inode_dirty+0x31/0x180
Jan 10 10:41:26 hudson-slave [262397.584963] [<c01d2a14>] ?
file_remove_suid+0x24/0x80
Jan 10 10:41:26 hudson-slave [262397.584970] [<c016fec0>] ?
autoremove_wake_function+0x20/0x50
Jan 10 10:41:26 hudson-slave [262397.584977] [<c0226b35>]
file_update_time+0xb5/0x130
Jan 10 10:41:26 hudson-slave [262397.584984] [<c01d4a88>]
__generic_file_aio_write+0x1b8/0x510
Jan 10 10:41:26 hudson-slave [262397.584991] [<c02c6ef4>] ?
journal_stop+0x124/0x2a0
Jan 10 10:41:26 hudson-slave [262397.584997] [<c0271c28>] ?
ext3_mark_iloc_dirty+0x18/0x30
Jan 10 10:41:26 hudson-slave [262397.585003] [<c01d4e37>]
generic_file_aio_write+0x57/0xc0
Jan 10 10:41:26 hudson-slave [262397.585008] [<c027255a>] ?
ext3_dirty_inode+0x5a/0x80
Jan 10 10:41:26 hudson-slave [262397.585016] [<c02126f4>]
do_sync_write+0xc4/0x100
Jan 10 10:41:26 hudson-slave [262397.585023] [<c016fea0>] ?
autoremove_wake_function+0x0/0x50
Jan 10 10:41:26 hudson-slave [262397.585029] [<c02289f3>] ?
notify_change+0x223/0x340
Jan 10 10:41:26 hudson-slave [262397.585035] [<c02749e0>] ?
ext3_ioctl+0x0/0x6b0
Jan 10 10:41:26 hudson-slave [262397.585042] [<c02ffa34>] ?
security_file_permission+0x14/0x20
Jan 10 10:41:26 hudson-slave [262397.585048] [<c0212894>] ?
rw_verify_area+0x64/0xe0
Jan 10 10:41:26 hudson-slave [262397.585054] [<c02129b2>] vfs_write+0xa2/0x1a0
Jan 10 10:41:26 hudson-slave [262397.585059] [<c0221529>] ?
do_vfs_ioctl+0x2e9/0x310
Jan 10 10:41:26 hudson-slave [262397.585065] [<c0212630>] ?
do_sync_write+0x0/0x100
Jan 10 10:41:26 hudson-slave [262397.585071] [<c02132d2>] sys_write+0x42/0x70
Jan 10 10:41:26 hudson-slave [262397.585078] [<c01096c3>]
sysenter_do_call+0x12/0x28
Jan 10 10:41:26 hudson-slave [262397.585083] ---[ end trace 3922152202b7311d
]---
Complete log is attached.
** Affects: linux (Ubuntu)
Importance: Undecided
Status: New
--
You received this bug notification because you are a member of Ubuntu
Bugs, which is subscribed to Ubuntu.
https://bugs.launchpad.net/bugs/701011
Title:
USB storage disconnects after certain period causing ext3 I/O errors and OOPS
--
ubuntu-bugs mailing list
[email protected]
https://lists.ubuntu.com/mailman/listinfo/ubuntu-bugs
