9 May
2005
9 May
'05
7:43 p.m.
Hi,
We're building an FC3/Planet CCRMA box using
2.6.11-0.3.rdt.rhfc3.ccrma and are experiencing bugish
behaviour with ieee1394b hotswap events.
Hardware:
Adaptec Fireworks with the TI chip
Cooldrives hotswap dual bay enclosure with Initio
bridge
NEC DVD-RW _nec DVD_RW ND-3520A
[root@stepdaddy log]# cat /proc/scsi/scsi
Attached devices:
Host: scsi0 Channel: 00 Id: 06 Lun: 00
Vendor: SONY Model: CD-RW CRX145S Rev: 1.0b
Type: CD-ROM ANSI SCSI
revision: 04
Host: scsi1 Channel: 00 Id: 00 Lun: 00
Vendor: ICP Model: Host Drive #00 Rev:
Type: Direct-Access ANSI SCSI
revision: 02
Host: scsi2 Channel: 00 Id: 00 Lun: 00
Vendor: WDC Model: WD400BB-00AUA1 Rev: 2.41
Type: Direct-Access ANSI SCSI
revision: 02
Host: scsi3 Channel: 00 Id: 00 Lun: 00
Vendor: WDC Model: WD800JB-00JJA0 Rev: 2.41
Type: Direct-Access ANSI SCSI
revision: 02
Host: scsi4 Channel: 00 Id: 00 Lun: 00
Vendor: _NEC Model: DVD_RW ND-3520A Rev: 1.04
Type: CD-ROM ANSI SCSI
revision: 02
Drivers:
<snip>
ohci1394 34308 0
ieee1394 308788 2 sbp2,ohci1394
scsi_mod 131272 7
sg,sbp2,sr_mod,gdth,sym53c8xx,scsi_transport_spi,sd_mod
<snip>
Some hardware is detected and we have a HAL event,
udev is gonna create the devices but we see an error
with hal.hotplug:
<snip>
May 7 20:10:28 stepdaddy udevsend[5034]: starting
udevd daemon
May 7 20:10:28 stepdaddy kernel: sbp2: $Rev: 1219 $
Ben Collins <bcollins(a)debian.org>
May 7 20:10:47 stepdaddy kernel: ieee1394: raw1394:
/dev/raw1394 device initialized
<snip>
May 7 20:22:08 stepdaddy hal.hotplug[5164]: DEVPATH
is not set
Then we see some SCSI Generic devices being detected
so I manually loaded the sg module.
May 7 20:36:36 stepdaddy kernel: Attached scsi
generic sg0 at scsi0, channel 0, id 6, lun 0, type 5
May 7 20:36:36 stepdaddy kernel: Attached scsi
generic sg1 at scsi1, channel 0, id 0, lun 0, type 0
Is the decision to load the sg module in response to
these events a sound or logical thing to do? Well, I
think it is because if we hotswap without sg loaded we
will hang the SCSI bus on a SCSI cache sync event.
That problem appears to be handled.
Here's log entries showing the sync event that hangs
without the sg module:
May 7 21:00:43 stepdaddy kernel: kjournald starting.
Commit interval 5 seconds
May 7 21:00:43 stepdaddy kernel: EXT3 FS on sda1,
internal journal
May 7 21:00:43 stepdaddy kernel: EXT3-fs: mounted
filesystem with ordered data mode.
May 7 21:02:42 stepdaddy kernel: kjournald starting.
Commit interval 5 seconds
May 7 21:02:42 stepdaddy kernel: EXT3 FS on sdc1,
internal journal
May 7 21:02:42 stepdaddy kernel: EXT3-fs: mounted
filesystem with ordered data mode.
May 7 21:04:56 stepdaddy kernel: Synchronizing SCSI
cache for disk sdb:
May 7 21:05:01 stepdaddy crond(pam_unix)[5626]:
session opened for user root by (uid=0)
May 7 21:05:01 stepdaddy crond(pam_unix)[5626]:
session closed for user root
May 7 21:07:26 stepdaddy gconfd (root-4224): Exiting
May 7 21:07:26 stepdaddy shutdown: shutting down for
system reboot
May 7 21:07:27 stepdaddy init: Switching to runlevel:
6
May 7 21:07:27 stepdaddy gdm(pam_unix)[3987]: session
closed for user root
May 7 21:07:28 stepdaddy cups-config-daemon:
cups-config-daemon -TERM succeeded
May 7 21:07:28 stepdaddy haldaemon: haldaemon
shutdown failed
May 7 21:07:28 stepdaddy messagebus: messagebus -TERM
succeeded
I wonder if loading the sg module early in the boot
will cause the ieee1394.agent to find drivers:
May 7 20:58:07 stepdaddy ieee1394.agent[5311]: ... no
drivers for IEEE1394 product 0x/0x/0x
Thoughts?
Continuing in the process here's more of the same:
May 7 20:58:07 stepdaddy kernel: scsi2 : SCSI
emulation for IEEE-1394 SBP-2 Devices
May 7 20:58:07 stepdaddy kernel: ieee1394: sbp2: Node
0-00:1023: Using 36byte inquiry workaround
May 7 20:58:08 stepdaddy kernel: ieee1394: sbp2:
Logged into SBP-2 device
May 7 20:58:08 stepdaddy kernel: Vendor: WDC
Model: WD800BB-00FJA0 Rev: 2.41
May 7 20:58:08 stepdaddy kernel: Type:
Direct-Access ANSI SCSI revision:
02
May 7 20:58:08 stepdaddy kernel: SCSI device sdb:
156301488 512-byte hdwr sectors (80026 MB)
May 7 20:58:08 stepdaddy kernel: SCSI device sdb:
drive cache: write back
May 7 20:58:08 stepdaddy kernel: SCSI device sdb:
156301488 512-byte hdwr sectors (80026 MB)
May 7 20:58:08 stepdaddy kernel: SCSI device sdb:
drive cache: write back
May 7 20:58:08 stepdaddy ieee1394.agent[5367]: ... no
drivers for IEEE1394 product 0x/0x/0x
May 7 20:58:08 stepdaddy kernel: sdb: sdb1
May 7 20:58:08 stepdaddy kernel: Attached scsi disk
sdb at scsi2, channel 0, id 0, lun 0
May 7 20:58:08 stepdaddy kernel: Attached scsi
generic sg2 at scsi2, channel 0, id 0, lun 0, type 0
May 7 20:58:08 stepdaddy scsi.agent[5377]: disk at
/devices/pci0000:00/0000:00:09.0/fw-host0/00027a0e000018b2/00027a0e000018b2-0/host2/target2:0:0/2:0:0:0
May 7 20:58:21 stepdaddy ieee1394.agent[5431]: ... no
drivers for IEEE1394 product 0x/0x/0x
LOAD SG
We finally load the sg module and four devices are
created:
scsi_mod 131272 7
sg,sbp2,sr_mod,gdth,sym53c8xx,scsi_transport_spi,sd_mod
May 9 14:23:57 stepdaddy udev[10876]: creating device
node '/dev/sg1'
May 9 14:23:57 stepdaddy udev[10875]: creating device
node '/dev/sg0'
May 9 14:23:57 stepdaddy udev[10877]: creating device
node '/dev/sg2'
May 9 14:23:58 stepdaddy udev[10878]: creating device
node '/dev/sg3'
So my question is, wart in da HAL are deez things fer
and is a fellar suddenly and unexpectedly vascillatin'
endlessly in some sorta 2001 space odessy or what?
Feelin' pretty smart about it, we decide to add to the
confusion by plugging in a new device:
NEC DVD-R
May 9 14:38:42 stepdaddy kernel: ieee1394: Error
parsing configrom for node 0-00:1023
<snip pam stuff>
May 9 14:40:50 stepdaddy gconfd (root-11032):
starting (version 2.8.1), pid 11032 user 'root'
May 9 14:40:50 stepdaddy gconfd (root-11032):
Resolved address
"xml:readonly:/etc/gconf/gconf.xml.mandatory" to a
read-only configuration source at position 0
May 9 14:40:50 stepdaddy gconfd (root-11032):
Resolved address "xml:readwrite:/root/.gconf" to a
writable configuration source at position 1
May 9 14:40:50 stepdaddy gconfd (root-11032):
Resolved address
"xml:readonly:/etc/gconf/gconf.xml.defaults" to a
read-only configuration source at position 2
May 9 14:40:50 stepdaddy kernel: program python is
using a deprecated SCSI ioctl, please convert it to
SG_IO
May 9 14:40:50 stepdaddy last message repeated 2
times
May 9 14:42:19 stepdaddy su(pam_unix)[
Anyone got a clue what in the deprecated ioctl is goin
on and where would we report that issue?
At this point the NEC DVD is plugged in but
undetected. Upon pulling the cables to the HD
enclosure the DVD is detected and we see the
following:
May 9 15:12:42 stepdaddy ieee1394.agent[11279]: ...
no drivers for IEEE1394 product 0x/0x/0x
May 9 15:12:45 stepdaddy kernel: ieee1394: Error
parsing configrom for node 0-00:1023
May 9 15:12:46 stepdaddy kernel: ieee1394: Error
parsing configrom for node 0-01:1023
May 9 15:12:47 stepdaddy kernel: ieee1394: Error
parsing configrom for node 0-02:1023
May 9 15:12:48 stepdaddy kernel: ieee1394: Error
parsing configrom for node 0-03:1023
May 9 15:12:49 stepdaddy kernel: scsi4 : SCSI
emulation for IEEE-1394 SBP-2 Devices
May 9 15:12:50 stepdaddy kernel: ieee1394: sbp2:
Logged into SBP-2 device
May 9 15:12:50 stepdaddy kernel: Vendor: _NEC
Model: DVD_RW ND-3520A Rev: 1.04
May 9 15:12:50 stepdaddy kernel: Type: CD-ROM
ANSI SCSI revision: 02
May 9 15:12:50 stepdaddy ieee1394.agent[11338]: ...
no drivers for IEEE1394 product 0x/0x/0x
May 9 15:12:50 stepdaddy kernel: sr1: scsi3-mmc
drive: 32x/32x writer cd/rw xa/form2 cdda tray
May 9 15:12:50 stepdaddy kernel: Attached scsi
generic sg4 at scsi4, channel 0, id 0, lun 0, type 5
May 9 15:12:50 stepdaddy udev[11370]: creating device
node '/dev/sg4'
May 9 15:12:50 stepdaddy udev[11351]: configured rule
in '/etc/udev/rules.d/50-udev.rules' at line 56
applied, added symlink 'cdrom%e'
May 9 15:12:50 stepdaddy udev[11351]: configured rule
in '/etc/udev/rules.d/50-udev.rules' at line 105
applied, added symlink 'dvd%e'
May 9 15:12:51 stepdaddy udev[11351]: configured rule
in '/etc/udev/rules.d/50-udev.rules' at line 108
applied, added symlink 'cdwriter%e'
May 9 15:12:51 stepdaddy udev[11351]: configured rule
in '/etc/udev/rules.d/50-udev.rules' at line 111
applied, added symlink 'dvdwriter%e'
May 9 15:12:51 stepdaddy udev[11351]: configured rule
in '/etc/udev/rules.d/50-udev.rules' at line 114
applied, 'sr1' becomes 'scd%n'
May 9 15:12:51 stepdaddy udev[11351]: creating device
node '/dev/scd1'
May 9 15:12:51 stepdaddy 05-pam_console.dev[11381]:
Restoring console permissions for /dev/scd1
/dev/cdrom1 /dev/dvd /dev/cdwriter1 /dev/dvdwriter
May 9 15:12:51 stepdaddy 05-pam_console.dev[11391]:
Restoring console permissions for /dev/sg4
May 9 15:12:51 stepdaddy scsi.agent[11321]: cdrom at
/devices/pci0000:00/0000:00:09.0/fw-host0/0050770520000bc9/0050770520000bc9-0/host4/target4:0:0/4:0:0:0
At this point we're mentally exhausted and out of
coffee but we've got just enough energy to sign this
letter,
dumb (aka ron) and dumber (aka dana)
__________________________________
Yahoo! Mail Mobile
Take Yahoo! Mail with you! Check email on your mobile phone.
http://mobile.yahoo.com/learn/mail