[Date Prev][Date Next] [Thread Prev][Thread Next] [Date Index] [Thread Index]

Bug#481525: linux-image-2.6.25-2-686: task hald-addon-stor blocked for more than 120 seconds



Package: linux-image-2.6.25-2-686
Version: 2.6.25-5
Followup-For: Bug #481525


This sounds like the problem I've had with an MSI cd-rw drive going bad:

Jun 24 09:03:13 victoria kernel: [39238.824892] INFO: task 
hald-addon-stor:3675 blocked for more than 120 seconds.
Jun 24 09:03:13 victoria kernel: [39238.824941] "echo 0 > 
/proc/sys/kernel/hung_task_timeout_secs" disables this message.
Jun 24 09:03:13 victoria kernel: [39238.824965] hald-addon-st D e604b3ed     
0  3675   3619
Jun 24 09:03:13 victoria kernel: [39238.824995]        d22019c0 00000082 
0000000c e604b3ed 000001b1 d2201b4c c128b0e0 00000000
Jun 24 09:03:13 victoria kernel: [39238.825048]        00000000 d48a15ce 
0004a099 00000000 00000000 d48382ac 00000088 d2f83d08
Jun 24 09:03:13 victoria kernel: [39238.825099]        7fffffff 7fffffff 
d2f83c74 00000002 c02bcd28 d4838260 00000000 00000092
Jun 24 09:03:13 victoria kernel: [39238.825149] Call Trace:
Jun 24 09:03:13 victoria kernel: [39238.825261]  [<d48a15ce>] 
cdrom_start_packet_command+0xb6/0xbd [ide_cd_mod]
Jun 24 09:03:13 victoria kernel: [39238.825390]  [<c02bcd28>] 
schedule_timeout+0x13/0x86
Jun 24 09:03:13 victoria kernel: [39238.825474]  [<c0180c61>] 
do_sys_poll+0x267/0x2e7
Jun 24 09:03:13 victoria kernel: [39238.825567]  [<c02bc441>] 
wait_for_common+0xd3/0x140
Jun 24 09:03:13 victoria kernel: [39238.825616]  [<c011c52f>] 
default_wake_function+0x0/0x8
Jun 24 09:03:13 victoria kernel: [39238.825696]  [<d4826ef2>] 
ide_do_drive_cmd+0xd6/0xf2 [ide_core]
Jun 24 09:03:13 victoria kernel: [39238.825943]  [<d48a1c65>] 
ide_cd_queue_pc+0x35/0xb4 [ide_cd_mod]
Jun 24 09:03:13 victoria kernel: [39238.825992]  [<c0110070>] 
lapic_watchdog_init+0x71/0xfc
Jun 24 09:03:13 victoria kernel: [39238.826059]  [<c02bcb67>] 
schedule+0x64c/0x66d
Jun 24 09:03:13 victoria kernel: [39238.826159]  [<d48a1f03>] 
cdrom_check_status+0x5a/0x65 [ide_cd_mod]
Jun 24 09:03:13 victoria kernel: [39238.826428]  [<c01d698f>] 
blk_end_sync_rq+0x0/0x25
Jun 24 09:03:13 victoria kernel: [39238.826518]  [<d48a38df>] 
ide_cdrom_check_media_change_real+0x1b/0x36 [ide_cd_mod]
Jun 24 09:03:13 victoria kernel: [39238.826582]  [<d489806e>] 
media_changed+0x40/0x6e [cdrom]
Jun 24 09:03:13 victoria kernel: [39238.826667]  [<c0195d7c>] 
check_disk_change+0x13/0x57
Jun 24 09:03:13 victoria kernel: [39238.826716]  [<d489bf2a>] 
cdrom_open+0x882/0x8f8 [cdrom]
Jun 24 09:03:13 victoria kernel: [39238.826777]  [<c017c1f3>] 
do_lookup+0x53/0x145
Jun 24 09:03:13 victoria kernel: [39238.826838]  [<c01843ea>] 
dput+0x15/0xbb
Jun 24 09:03:13 victoria kernel: [39238.826876]  [<c017e1a9>] 
__link_path_walk+0xa5b/0xb67
Jun 24 09:03:13 victoria kernel: [39238.826930]  [<c01de860>] 
kobject_get+0xf/0x13
Jun 24 09:03:13 victoria kernel: [39238.826993]  [<c01d860d>] 
get_disk+0x33/0x49
Jun 24 09:03:13 victoria kernel: [39238.827041]  [<c01d862a>] 
exact_lock+0x7/0xd
Jun 24 09:03:13 victoria kernel: [39238.827073]  [<c0241e22>] 
kobj_lookup+0xe4/0x10e
Jun 24 09:03:13 victoria kernel: [39238.827144]  [<d48a14f1>] 
idecd_open+0x44/0x6b [ide_cd_mod]
Jun 24 09:03:13 victoria kernel: [39238.827212]  [<c019637b>] 
do_open+0xa1/0x278
Jun 24 09:03:13 victoria kernel: [39238.827281]  [<c01966cd>] 
blkdev_open+0x0/0x4d
Jun 24 09:03:13 victoria kernel: [39238.827309]  [<c01966f2>] 
blkdev_open+0x25/0x4d
Jun 24 09:03:13 victoria kernel: [39238.827353]  [<c0174aeb>] 
__dentry_open+0x10d/0x1fc
Jun 24 09:03:13 victoria kernel: [39238.827431]  [<c0174bf6>] 
nameidata_to_filp+0x1c/0x2c
Jun 24 09:03:13 victoria kernel: [39238.827484]  [<c017f38a>] 
do_filp_open+0x34f/0x6b0
Jun 24 09:03:13 victoria kernel: [39238.827571]  [<d4899322>] 
cdrom_release+0x179/0x1ae [cdrom]
Jun 24 09:03:13 victoria kernel: [39238.827628]  [<d4a45183>] 
snd_emu10k1_playback_pointer+0x2a/0x52 [snd_emu10k1]
Jun 24 09:03:13 victoria kernel: [39238.827806]  [<d4a4724d>] 
snd_emu10k1_voice_intr_ack+0x15/0x52 [snd_emu10k1]
Jun 24 09:03:13 victoria kernel: [39238.827987]  [<c0174908>] 
do_sys_open+0x40/0xb0
Jun 24 09:03:13 victoria kernel: [39238.828051]  [<c01749bc>] 
sys_open+0x1e/0x23
Jun 24 09:03:13 victoria kernel: [39238.828102]  [<c0105863>] 
sysenter_past_esp+0x78/0xb1

This problem happened with a large number of test kernels as well (can't 
be sure if any recent kernels *didn't* show this problem).

It would be nice if the kernel could handle cd drives going bad more 
gracefully. This problem also locked up dosbox.

After changing to a known good pioneer dvd-rw drive, I started getting 
the following errors when playing an audio cd:

Jun 24 22:51:57 victoria kernel: [ 7076.365804] hdc: command error: 
status=0x51 { DriveReady SeekComplete Error }
Jun 24 22:51:57 victoria kernel: [ 7076.365876] hdc: command error: 
error=0x50 { LastFailedSense=0x05 }
Jun 24 22:51:57 victoria kernel: [ 7076.365909] ide: failed opcode was: 
unknown
Jun 24 22:51:57 victoria kernel: [ 7076.366282] ATAPI device hdc:
Jun 24 22:51:57 victoria kernel: [ 7076.366301]   Error: Illegal request 
-- (Sense key=0x05)
Jun 24 22:51:57 victoria kernel: [ 7076.366335]   Illegal mode for this 
track or incompatible medium -- (asc=0x64, ascq=0x00)
Jun 24 22:51:57 victoria kernel: [ 7076.366359]   The failed "Read 10" 
packet command was:
Jun 24 22:51:57 victoria kernel: [ 7076.366371]   "28 00 00 00 00 00 00 
00 08 00 00 00 00 00 00 00 "
Jun 24 22:51:57 victoria kernel: [ 7076.366462] end_request: I/O error, 
dev hdc, sector 0
Jun 24 22:51:57 victoria kernel: [ 7076.366495] Buffer I/O error on 
device hdc, logical block 0
Jun 24 22:51:57 victoria kernel: [ 7076.366545] Buffer I/O error on 
device hdc, logical block 1
Jun 24 22:51:57 victoria kernel: [ 7076.366572] Buffer I/O error on 
device hdc, logical block 2
Jun 24 22:51:57 victoria kernel: [ 7076.366598] Buffer I/O error on 
device hdc, logical block 3
Jun 24 22:51:57 victoria kernel: [ 7076.367827] hdc: command error: 
status=0x51 { DriveReady SeekComplete Error }
Jun 24 22:51:57 victoria kernel: [ 7076.367872] hdc: command error: 
error=0x50 { LastFailedSense=0x05 }
Jun 24 22:51:57 victoria kernel: [ 7076.367902] ide: failed opcode was: 
unknown
Jun 24 22:51:57 victoria kernel: [ 7076.372053] ATAPI device hdc:
Jun 24 22:51:57 victoria kernel: [ 7076.372080]   Error: Illegal request 
-- (Sense key=0x05)
Jun 24 22:51:57 victoria kernel: [ 7076.372114]   Illegal mode for this 
track or incompatible medium -- (asc=0x64, ascq=0x00)
Jun 24 22:51:57 victoria kernel: [ 7076.372138]   The failed "Read 10" 
packet command was:
Jun 24 22:51:57 victoria kernel: [ 7076.372149]   "28 00 00 00 00 00 00 
00 02 00 00 00 00 00 00 00 "
Jun 24 22:51:57 victoria kernel: [ 7076.372239] end_request: I/O error, 
dev hdc, sector 0
Jun 24 22:51:57 victoria kernel: [ 7076.372268] Buffer I/O error on 
device hdc, logical block 0
Jun 24 22:51:57 victoria kernel: [ 7076.473670] hdc: command error: 
status=0x51 { DriveReady SeekComplete Error }
Jun 24 22:51:57 victoria kernel: [ 7076.473729] hdc: command error: 
error=0x50 { LastFailedSense=0x05 }
Jun 24 22:51:57 victoria kernel: [ 7076.473760] ide: failed opcode was: 
unknown
Jun 24 22:51:57 victoria kernel: [ 7076.474080] ATAPI device hdc:
Jun 24 22:51:57 victoria kernel: [ 7076.474101]   Error: Illegal request 
-- (Sense key=0x05)
Jun 24 22:51:57 victoria kernel: [ 7076.474134]   Illegal mode for this 
track or incompatible medium -- (asc=0x64, ascq=0x00)
Jun 24 22:51:57 victoria kernel: [ 7076.474158]   The failed "Read 10" 
packet command was:
Jun 24 22:51:57 victoria kernel: [ 7076.474170]   "28 00 00 00 00 00 00 
00 02 00 00 00 00 00 00 00 "
Jun 24 22:51:57 victoria kernel: [ 7076.474258] end_request: I/O error, 
dev hdc, sector 0
Jun 24 22:51:57 victoria kernel: [ 7076.474260] Buffer I/O error on 
device hdc, logical block 0
Jun 24 22:51:57 victoria kernel: [ 7076.493664] hdc: command error: 
status=0x51 { DriveReady SeekComplete Error }
Jun 24 22:51:57 victoria kernel: [ 7076.493718] hdc: command error: 
error=0x50 { LastFailedSense=0x05 }
Jun 24 22:51:57 victoria kernel: [ 7076.493749] ide: failed opcode was: 
unknown
Jun 24 22:51:57 victoria kernel: [ 7076.498497] ATAPI device hdc:
Jun 24 22:51:57 victoria kernel: [ 7076.498520]   Error: Illegal request 
-- (Sense key=0x05)
Jun 24 22:51:57 victoria kernel: [ 7076.498554]   Illegal mode for this 
track or incompatible medium -- (asc=0x64, ascq=0x00)
Jun 24 22:51:57 victoria kernel: [ 7076.498578]   The failed "Read 10" 
packet command was:
Jun 24 22:51:57 victoria kernel: [ 7076.498590]   "28 00 00 00 00 00 00 
00 02 00 00 00 00 00 00 00 "
Jun 24 22:51:57 victoria kernel: [ 7076.498679] end_request: I/O error, 
dev hdc, sector 0
Jun 24 22:51:57 victoria kernel: [ 7076.498710] Buffer I/O error on 
device hdc, logical block 0
Jun 24 22:51:57 victoria kernel: [ 7076.559279] hdc: command error: 
status=0x51 { DriveReady SeekComplete Error }
Jun 24 22:51:57 victoria kernel: [ 7076.559356] hdc: command error: 
error=0x50 { LastFailedSense=0x05 }
Jun 24 22:51:57 victoria kernel: [ 7076.559388] ide: failed opcode was: 
unknown
Jun 24 22:51:57 victoria kernel: [ 7076.559708] ATAPI device hdc:
Jun 24 22:51:57 victoria kernel: [ 7076.559728]   Error: Illegal request 
-- (Sense key=0x05)
Jun 24 22:51:57 victoria kernel: [ 7076.559762]   Illegal mode for this 
track or incompatible medium -- (asc=0x64, ascq=0x00)
Jun 24 22:51:57 victoria kernel: [ 7076.559786]   The failed "Read 10" 
packet command was:
Jun 24 22:51:57 victoria kernel: [ 7076.559798]   "28 00 00 00 00 00 00 
00 02 00 00 00 00 00 00 00 "
Jun 24 22:51:57 victoria kernel: [ 7076.559888] end_request: I/O error, 
dev hdc, sector 0
Jun 24 22:51:57 victoria kernel: [ 7076.559920] Buffer I/O error on 
device hdc, logical block 0
Jun 24 22:51:57 victoria kernel: [ 7076.579360] hdc: command error: 
status=0x51 { DriveReady SeekComplete Error }
Jun 24 22:51:57 victoria kernel: [ 7076.579435] hdc: command error: 
error=0x50 { LastFailedSense=0x05 }
Jun 24 22:51:57 victoria kernel: [ 7076.579467] ide: failed opcode was: 
unknown
Jun 24 22:51:57 victoria kernel: [ 7076.584008] ATAPI device hdc:
Jun 24 22:51:57 victoria kernel: [ 7076.584053]   Error: Illegal request 
-- (Sense key=0x05)
Jun 24 22:51:57 victoria kernel: [ 7076.584088]   Illegal mode for this 
track or incompatible medium -- (asc=0x64, ascq=0x00)
Jun 24 22:51:57 victoria kernel: [ 7076.584113]   The failed "Read 10" 
packet command was:
Jun 24 22:51:57 victoria kernel: [ 7076.584124]   "28 00 00 00 00 00 00 
00 02 00 00 00 00 00 00 00 "
Jun 24 22:51:57 victoria kernel: [ 7076.584216] end_request: I/O error, 
dev hdc, sector 0
Jun 24 22:51:57 victoria kernel: [ 7076.584249] Buffer I/O error on 
device hdc, logical block 0

Any suggestions beyond the usual disabling DMA? The cd-rw and now 
dvd-rw drive is the only device on the secondary IDE channel.

hdparm reports:

# hdparm /dev/hdc

/dev/hdc:
 IO_support    =  0 (default)
 unmaskirq     =  0 (off)
 using_dma     =  1 (on)
 keepsettings  =  0 (off)
 readonly      =  0 (off)
 readahead     = 256 (on)
 HDIO_GETGEO failed: Inappropriate ioctl for device


-- Package-specific info:

-- System Information:
Debian Release: lenny/sid
  APT prefers unstable
  APT policy: (500, 'unstable'), (500, 'testing'), (500, 'stable')
Architecture: i386 (i686)

Kernel: Linux 2.6.26-rc7 (SMP w/1 CPU core; PREEMPT)
Locale: LANG=en_AU.UTF-8, LC_CTYPE=en_AU.UTF-8 (charmap=UTF-8)
Shell: /bin/sh linked to /bin/bash

Versions of packages linux-image-2.6.25-2-686 depends on:
ii  debconf [debconf-2.0]         1.5.22     Debian configuration management sy
ii  initramfs-tools [linux-initra 0.92b      tools for generating an initramfs
ii  module-init-tools             3.4-1      tools for managing Linux kernel mo
ii  yaird [linux-initramfs-tool]  0.0.12-25  Yet Another mkInitRD

Versions of packages linux-image-2.6.25-2-686 recommends:
ii  libc6-i686                    2.7-12     GNU C Library: Shared libraries [i

-- debconf-show failed



Reply to: