SCSI Bus Resets after hal upgraded to .5.5.1 from .5.4
Pat Kellaher
qqxm5gf39 at siren.ocn.ne.jp
Sun Dec 18 23:35:13 PST 2005
I am running Slackware Linux 10.2 with Dropline Gnome 2.12.2 and am
currently running kernel 2.6.14.4. I noticed the SCSI bus that my
optical drives are on (Pioneer DVD-ROM 304 and Plextor 1210 CDRW)
consistently reseting after I upgraded to Dropline Gnome 2.12.2. I
tracked the problem down to hald. If I stopped hald then the reseting
stopped. If I started hald then the reset happened. At the time I was
using kernel 2.6.14.3 and hald had been upgraded from .5.4 to .5.5.1.
To troubleshoot, I am starting hald like this:
/usr/sbin/hald --daemon=yes --retain-privileges --verbose=yes
--use-syslog
The next line in rc.hal is:
echo /sbin/udevsend >/proc/sys/kernel/hotplug
Here are snippets from /var/log/messages:
Dec 19 16:18:00 wecoyote hald[11854]: 16:18:00.217 [I] hald.c:511: hal
0.5.5.1
Dec 19 16:18:00 wecoyote hald[11854]: 16:18:00.217 [I] hald.c:519: Will
daemonize
Dec 19 16:18:00 wecoyote hald[11854]: 16:18:00.217 [I] hald.c:520:
Becoming a daemon
Dec 19 16:18:00 wecoyote hald[11855]: 16:18:00.218 [I] hald_dbus.c:3048:
local server is listening at
unix:abstract=/tmp/hald-local/dbus-8dPaxlfJMC,guid=a85ea6436d6279ae147a64a90d1a3a00
Dec 19 16:18:00 wecoyote hald[11855]: 16:18:00.218 [I] osspec.c:347:
sysfs mount point is '/sys'
Dec 19 16:18:00 wecoyote hald[11855]: 16:18:00.218 [I] osspec.c:352:
proc mount point is '/proc'
Dec 19 16:18:00 wecoyote hald[11855]: 16:18:00.221 [I] osspec.c:524:
Synthesizing sysfs events...
Dec 19 16:18:00 wecoyote hald[11855]: 16:18:00.223 [I] coldplug.c:129:
dev_root is /dev
Dec 19 16:18:00 wecoyote hald[11855]: 16:18:00.246 [I] coldplug.c:230:
sysfs_path /sys/class/tty/ttyS1 not in udevdb
Dec 19 16:18:00 wecoyote hald[11855]: 16:18:00.246 [I] coldplug.c:245:
return sysfs_path /dev/ttyS1
Dec 19 16:18:00 wecoyote hald[11855]: 16:18:00.246 [I] coldplug.c:230:
sysfs_path /sys/class/tty/ttyS0 not in udevdb
Dec 19 16:18:00 wecoyote hald[11855]: 16:18:00.246 [I] coldplug.c:245:
return sysfs_path /dev/ttyS0
Dec 19 16:18:00 wecoyote hald[11855]: 16:18:00.248 [I] coldplug.c:230:
sysfs_path /sys/class/net/eth0 not in udevdb
Dec 19 16:18:00 wecoyote hald[11855]: 16:18:00.249 [I] coldplug.c:230:
sysfs_path /sys/class/spi_host/host0 not in udevdb
Dec 19 16:18:00 wecoyote hald[11855]: 16:18:00.249 [I] coldplug.c:230:
sysfs_path /sys/class/scsi_host/host0 not in udevdb
Dec 19 16:18:00 wecoyote hald[11855]: 16:18:00.249 [I] coldplug.c:230:
sysfs_path /sys/class/spi_transport/target0:0:4 not in udevdb
Dec 19 16:18:00 wecoyote hald[11855]: 16:18:00.249 [I] coldplug.c:230:
sysfs_path /sys/class/scsi_generic/sg3 not in udevdb
Dec 19 16:18:00 wecoyote hald[11855]: 16:18:00.249 [I] coldplug.c:245:
return sysfs_path /dev/sg3
Dec 19 16:18:00 wecoyote hald[11855]: 16:18:00.249 [I] coldplug.c:230:
sysfs_path /sys/class/scsi_device/0:0:4:0 not in udevdb
Dec 19 16:18:00 wecoyote hald[11855]: 16:18:00.249 [I] coldplug.c:230:
sysfs_path /sys/class/spi_transport/target0:0:3 not in udevdb
Dec 19 16:18:00 wecoyote hald[11855]: 16:18:00.250 [I] coldplug.c:230:
sysfs_path /sys/class/scsi_generic/sg2 not in udevdb
Dec 19 16:18:00 wecoyote hald[11855]: 16:18:00.250 [I] coldplug.c:245:
return sysfs_path /dev/sg2
Dec 19 16:18:00 wecoyote hald[11855]: 16:18:00.250 [I] coldplug.c:230:
sysfs_path /sys/class/scsi_device/0:0:3:0 not in udevdb
Dec 19 16:18:00 wecoyote hald[11855]: 16:18:00.250 [I] coldplug.c:230:
sysfs_path /sys/class/spi_transport/target0:0:2 not in udevdb
Dec 19 16:18:00 wecoyote hald[11855]: 16:18:00.250 [I] coldplug.c:230:
sysfs_path /sys/class/scsi_generic/sg1 not in udevdb
Dec 19 16:18:00 wecoyote hald[11855]: 16:18:00.250 [I] coldplug.c:245:
return sysfs_path /dev/sg1
Dec 19 16:18:00 wecoyote hald[11855]: 16:18:00.250 [I] coldplug.c:230:
sysfs_path /sys/class/scsi_device/0:0:2:0 not in udevdb
Dec 19 16:18:00 wecoyote hald[11855]: 16:18:00.251 [I] coldplug.c:230:
sysfs_path /sys/class/spi_transport/target0:0:0 not in udevdb
Dec 19 16:18:00 wecoyote hald[11855]: 16:18:00.251 [I] coldplug.c:230:
sysfs_path /sys/class/scsi_generic/sg0 not in udevdb
Dec 19 16:18:00 wecoyote hald[11855]: 16:18:00.251 [I] coldplug.c:245:
return sysfs_path /dev/sg0
Dec 19 16:18:00 wecoyote hald[11855]: 16:18:00.251 [I] coldplug.c:230:
sysfs_path /sys/class/scsi_device/0:0:0:0 not in udevdb
[snip]
Dec 19 16:18:02 wecoyote hald[11855]: 16:18:02.684 [I] blockdev.c:180:
Update mount point for
/org/freedesktop/Hal/devices/volume_part_1_size_542375936 (device_file
/dev/sr1)
Dec 19 16:18:02 wecoyote hald[11855]: 16:18:02.986 [I] blockdev.c:227:
Clearing mount point for /dev/sr1
Dec 19 16:18:02 wecoyote hald[11855]: 16:18:02.989 [I] blockdev.c:139:
Add callouts completed
udi=/org/freedesktop/Hal/devices/volume_part_1_size_542375936
Dec 19 16:18:02 wecoyote hald[11855]: 16:18:02.989 [I] hald.c:89: Added
device to GDL; udi=/org/freedesktop/Hal/devices/volume_part_1_size_542375936
Dec 19 16:18:02 wecoyote hald[11855]: 16:18:02.989 [I] hald.c:653:
Device probing completed
Dec 19 16:18:02 wecoyote hald[11855]: 16:18:02.989 [I] hald_dbus.c:3063:
entering
Dec 19 16:18:03 wecoyote kernel: sr 0:0:4:0: SCSI error: return code =
0x10000
Dec 19 16:18:44 wecoyote last message repeated 3 times
Dec 19 16:19:33 wecoyote last message repeated 3 times
Dec 19 16:19:36 wecoyote hald[11855]: 16:19:36.830 [I] hald.c:273:
Caught SIGTERM, initiating shutdown
Dec 19 16:19:36 wecoyote hald[11855]: 16:19:36.830 [I] util.c:1262:
Killing helper with pid 11890
Dec 19 16:19:36 wecoyote hald[11855]: 16:19:36.830 [I] util.c:1262:
Killing helper with pid 11877
Dec 19 16:19:36 wecoyote hald[11855]: 16:19:36.830 [I] util.c:1262:
Killing helper with pid 11874
Dec 19 16:19:36 wecoyote hald[11855]: 16:19:36.830 [I] util.c:1262:
Killing helper with pid 11861
Dec 19 16:19:36 wecoyote hald[11855]: 16:19:36.830 [I] hald.c:275:
Killed 134679508 helpers; exiting
Here is /var/log/syslog during that time:
Dec 19 16:18:00 wecoyote hald[11855]: 16:18:00.358 [E] acpi.c:766:
Couldn't open /proc/acpi/battery: Error opening directory '/proc/acpi/b
attery': No such file or directory
Dec 19 16:18:00 wecoyote hald[11855]: 16:18:00.358 [E] acpi.c:766:
Couldn't open /proc/acpi/ac_adapter: Error opening directory '/proc/acp
i/ac_adapter': No such file or directory
Dec 19 16:18:00 wecoyote hald[11855]: 16:18:00.358 [E] acpi.c:766:
Couldn't open /proc/acpi/button/lid: Error opening directory '/proc/acp
i/button/lid': No such file or directory
Dec 19 16:18:00 wecoyote hald[11855]: 16:18:00.520 [E] util.c:456:
Cannot open '/sys/devices/pci0000:00/0000:00:08.0/0000:01:08.2/fw-host0
/00023c0021044b30/00023c0021044b30-0/../vendor_oui'
Dec 19 16:18:00 wecoyote hald[11855]: 16:18:00.520 [E] util.c:315:
Cannot open '/sys/devices/pci0000:00/0000:00:08.0/0000:01:08.2/fw-host0
/00023c0021044b30/00023c0021044b30-0/model_id'
Dec 19 16:18:00 wecoyote hald[11855]: 16:18:00.608 [E] util.c:456:
Cannot open '/sys/devices/pci0000:00/0000:00:02.2/usb1/1-2/serial'
Dec 19 16:18:00 wecoyote hald[11855]: 16:18:00.608 [E] util.c:456:
Cannot open '/sys/devices/pci0000:00/0000:00:02.2/usb1/1-2/serial'
Dec 19 16:18:01 wecoyote hald[11855]: 16:18:01.311 [W] blockdev.c:218:
Could not find /dev/sdc1 in /proc/mounts retry to find.
Dec 19 16:18:01 wecoyote hald[11855]: 16:18:01.312 [W] blockdev.c:213:
Could not find /dev/sdc1 in /proc/mounts, no second retry.
Dec 19 16:18:01 wecoyote hald[11855]: 16:18:01.834 [W] blockdev.c:218:
Could not find /dev/sda3 in /proc/mounts retry to find.
Dec 19 16:18:01 wecoyote hald[11855]: 16:18:01.835 [W] blockdev.c:213:
Could not find /dev/sda3 in /proc/mounts, no second retry.
Dec 19 16:18:02 wecoyote hald[11855]: 16:18:02.149 [W] blockdev.c:218:
Could not find /dev/sda2 in /proc/mounts retry to find.
Dec 19 16:18:02 wecoyote hald[11855]: 16:18:02.150 [W] blockdev.c:213:
Could not find /dev/sda2 in /proc/mounts, no second retry.
Dec 19 16:18:02 wecoyote hald[11855]: 16:18:02.464 [W] blockdev.c:218:
Could not find /dev/sda1 in /proc/mounts retry to find.
Dec 19 16:18:02 wecoyote hald[11855]: 16:18:02.465 [W] blockdev.c:213:
Could not find /dev/sda1 in /proc/mounts, no second retry.
Dec 19 16:18:02 wecoyote hald[11855]: 16:18:02.985 [W] blockdev.c:218:
Could not find /dev/sr1 in /proc/mounts retry to find.
Dec 19 16:18:02 wecoyote hald[11855]: 16:18:02.985 [W] blockdev.c:213:
Could not find /dev/sr1 in /proc/mounts, no second retry.
Dec 19 16:18:03 wecoyote kernel: (scsi0:A:4:0): No or incomplete CDB
sent to device.
Dec 19 16:18:03 wecoyote kernel: scsi0: Issued Channel A Bus Reset. 1
SCBs aborted
Dec 19 16:18:15 wecoyote kernel: (scsi0:A:4:0): No or incomplete CDB
sent to device.
Dec 19 16:18:15 wecoyote kernel: scsi0: Issued Channel A Bus Reset. 1
SCBs aborted
Dec 19 16:18:31 wecoyote kernel: (scsi0:A:4:0): No or incomplete CDB
sent to device.
Dec 19 16:18:31 wecoyote kernel: scsi0: Issued Channel A Bus Reset. 1
SCBs aborted
Dec 19 16:18:44 wecoyote kernel: (scsi0:A:4:0): No or incomplete CDB
sent to device.
Dec 19 16:18:44 wecoyote kernel: scsi0: Issued Channel A Bus Reset. 1
SCBs aborted
Dec 19 16:19:04 wecoyote kernel: (scsi0:A:4:0): No or incomplete CDB
sent to device.
Dec 19 16:19:04 wecoyote kernel: scsi0: Issued Channel A Bus Reset. 1
SCBs aborted
Dec 19 16:19:18 wecoyote kernel: (scsi0:A:4:0): No or incomplete CDB
sent to device.
Dec 19 16:19:18 wecoyote kernel: scsi0: Issued Channel A Bus Reset. 1
SCBs aborted
Dec 19 16:19:33 wecoyote kernel: (scsi0:A:4:0): No or incomplete CDB
sent to device.
Dec 19 16:19:33 wecoyote kernel: scsi0: Issued Channel A Bus Reset. 1
SCBs aborted
Here is the contents of /proc/scsi/scsi:
# cat /proc/scsi/scsi
Attached devices:
Host: scsi0 Channel: 00 Id: 00 Lun: 00
Vendor: QUANTUM Model: ATLAS10K2-TY184L Rev: DDD6
Type: Direct-Access ANSI SCSI revision: 03
Host: scsi0 Channel: 00 Id: 02 Lun: 00
Vendor: QUANTUM Model: ATLAS10K2-TY184L Rev: DDD6
Type: Direct-Access ANSI SCSI revision: 03
Host: scsi0 Channel: 00 Id: 03 Lun: 00
Vendor: PIONEER Model: DVD-ROM DVD-304 Rev: 1.03
Type: CD-ROM ANSI SCSI revision: 02
Host: scsi0 Channel: 00 Id: 04 Lun: 00
Vendor: PLEXTOR Model: CD-R PX-W1210S Rev: 1.06
Type: CD-ROM ANSI SCSI revision: 02
Host: scsi1 Channel: 00 Id: 00 Lun: 00
Vendor: WDC WD80 Model: 0UE-00HCT0 Rev: 0 0
Type: Direct-Access ANSI SCSI revision: 02
(Note: That WD80 is an external USB HD)
Here are the contents of /proc/scsi/aic7xxx/0:
/proc/scsi/aic7xxx# cat 0
Adaptec AIC7xxx driver version: 7.0
Adaptec 29160 Ultra160 SCSI adapter
aic7892: Ultra160 Wide Channel A, SCSI Id=7, 32/253 SCBs
Allocated SCBs: 36, SG List Length: 128
Serial EEPROM:
0xc33a 0xc33a 0xc33a 0xc33a 0xc33a 0xc13a 0xc13a 0xc13a
0xc13a 0xc13a 0xc13a 0xc13a 0xc13a 0xc13a 0xc13a 0xc13a
0xb8f4 0x7c5d 0x2807 0x0010 0xffff 0xffff 0xffff 0xffff
0xffff 0xffff 0xffff 0xffff 0xffff 0xffff 0x0250 0x7d4e
Target 0 Negotiation Settings
User: 160.000MB/s transfers (80.000MHz DT, offset 127, 16bit)
Goal: 160.000MB/s transfers (80.000MHz DT, offset 127, 16bit)
Curr: 160.000MB/s transfers (80.000MHz DT, offset 127, 16bit)
Channel A Target 0 Lun 0 Settings
Commands Queued 36831
Commands Active 0
Command Openings 32
Max Tagged Openings 32
Device Queue Frozen Count 0
Target 1 Negotiation Settings
User: 160.000MB/s transfers (80.000MHz DT, offset 127, 16bit)
Target 2 Negotiation Settings
User: 160.000MB/s transfers (80.000MHz DT, offset 127, 16bit)
Goal: 160.000MB/s transfers (80.000MHz DT, offset 127, 16bit)
Curr: 3.300MB/s transfers
Channel A Target 2 Lun 0 Settings
Commands Queued 75566
Commands Active 0
Command Openings 32
Max Tagged Openings 32
Device Queue Frozen Count 0
Target 3 Negotiation Settings
User: 160.000MB/s transfers (80.000MHz DT, offset 127, 16bit)
Goal: 20.000MB/s transfers (20.000MHz, offset 16)
Curr: 20.000MB/s transfers (20.000MHz, offset 16)
Channel A Target 3 Lun 0 Settings
Commands Queued 28147
Commands Active 0
Command Openings 1
Max Tagged Openings 0
Device Queue Frozen Count 0
Target 4 Negotiation Settings
User: 160.000MB/s transfers (80.000MHz DT, offset 127, 16bit)
Goal: 20.000MB/s transfers (20.000MHz, offset 16)
Curr: 20.000MB/s transfers (20.000MHz, offset 16)
Channel A Target 4 Lun 0 Settings
Commands Queued 903256
Commands Active 0
Command Openings 1
Max Tagged Openings 0
Device Queue Frozen Count 0
What could be causing my SCSI bus resets?
Pat
More information about the hal
mailing list