Skip site navigation (1)Skip section navigation (2)
Date:      Wed, 24 Sep 2003 18:37:01 +0200 (CEST)
From:      Barry Bouwsma <freebsd-misuser@remove-NOSPAM-to-reply.NOSPAM.dyndns.dk>
To:        FreeBSD Firewire Folks <firewire@freebsd.org>
Subject:   More about boot-time firewire device detection...
Message-ID:  <200309241637.h8OGb1J02805@Mail.NOSPAM.DynDNS.dK>

next in thread | raw e-mail | index | archive | help
[drop hostname part of above IPv6-only address if you want to mail me via
 IPv4, or better, drop my address entirely and I'll read the list archives]


Hello hello hello.

I wrote earlier that my Firewire/USB external drive was only found after
boot followed by detach/reattach with the latest (recent) firewire codes,
and an unneeded patch to detach the CAM layer at detach.

Well, I've moved to a different machine, using the same cards, to allow me
to panic and poweroff to juggle hardware without inconveniencing other
long-running programs.  This machine had only a 4.5-RC kernel, now 4.9PRE,
an unknown userland from around the same time, and I'm trying to use the
latest kernel modules.  None of my patch hacks have been applied.

I wrote that the latest firewire/sbp codes failed to find an attached
drive at boot, when loaded from loader.conf.  This may still be true, I'm
going to check Real Soon Now.  Yes, it's true.  Details follow.

However, if *after* boot I kldload sbp/firewire with the drive attached, it
appears to detect the drive fine and make it available for mounting, as
desired.  No need to detach/reattach the cable.


Here is part of the dmesg at boot with auto-load by loader.conf:

[snip; verbose boot lost firewire-related messages prior to this]
node0: explore addr=0x400
Current DB 0
ch = 0
 Current OP   KEY INT BR   len     Addr   Depend Stat: Cnt
02682080 OUTL ST2 ALL ALL    12 00000000 02682100 8412:7cd0 RUN,ACTIVE, ack pend(12)
0x00800540 0xffc0ffff 0xf0000400 0x00000000
fw_rcv: unknown response tcode=6 src=0xffc0 tl=0x2 rt=1 data=0xc9354404
try ad-hoc work around!!
node0: callback addr=0x400
node0: explore addr=0x40c
Current DB 0
ch = 0
 Current OP   KEY INT BR   len     Addr   Depend Stat: Cnt
02682100 OUTL ST2 ALL ALL    12 00000000 02682180 8412:7d19 RUN,ACTIVE, ack pend(12)
0x00800940 0xffc0ffff 0xf000040c 0x00000000
node0: callback addr=0x40c
node0: explore addr=0x410
    [ very large snip .... ]

node0: callback addr=0x50c
node0: explore addr=0x510
Current DB 0
ch = 0
 Current OP   KEY INT BR   len     Addr   Depend Stat: Cnt
02682700 OUTL ST2 ALL ALL    12 00000000 02682780 8412:9b39 RUN,ACTIVE, ack pend(12)
0x00803940 0xffc0ffff 0xf0000510 0x00000000
node0: callback addr=0x510
bus_explore done
sbp_post_explore (sbp_cold=2)
sbp_post_explore: EUI:0010b920003dbcb3 attached
target 0 lun 0 found
sbp0:0:0 ordered:1 type:14 EUI:0010b920003dbcb3 node:0 speed:2 maxrec:0 new!
sbp0:0:0 'Maxtor' '5000XT  v1.00.00' '010000'
Mounting root from ufs:/dev/ad0s1a
ad0s1: type 0xa5, start 63, end = 2503871, size 2503809 : OK
start_init: trying /sbin/init
sbp0:0:0 LOGIN
sbp: alloc 1 xfer
fwohci0: maxdesc: 3
dbdump err ch = 0 cmd = 0x026827a1
sbp0:0:0 login: len 16, ID 0, cmd 0000fffff0100000, recon_hold 0
sbp0:0:0 sbp_busy_timeout
Current DB 0
ch = 0
 Current OP   KEY INT BR   len     Addr   Depend Stat: Cnt
02682800 OUTL ST2 ALL ALL    16 00000000 02682880 8412:dbb7 RUN,ACTIVE, ack pend(12)
0x00824100 0xffc0ffff 0xf0000210 0x0f000002
sbp0:0:0 sbp_agent_reset
Current DB 0
ch = 0
 Current OP   KEY INT BR   len     Addr   Depend Stat: Cnt
02682880 OUTL ST2 ALL ALL    16 00000000 02682900 8412:dbe8 RUN,ACTIVE, ack pend(12)
0x00824500 0xffc0ffff 0xf0100004 0x0f000000
sbp0:0:0 sbp_do_attach


It never goes any further than this, until I physically detach and re-attach
the cable.  Then, with a new boot, auto-loaded sbp/firewire kernel modules:

[ very big snip, here it's not made available at boot: ... ]
node0: callback addr=0x510
bus_explore done
sbp_post_explore (sbp_cold=2)
sbp_post_explore: EUI:0010b920003dbcb3 attached
target 0 lun 0 found
sbp0:0:0 ordered:1 type:14 EUI:0010b920003dbcb3 node:0 speed:2 maxrec:0 new!
sbp0:0:0 'Maxtor' '5000XT  v1.00.00' '010000'
Mounting root from ufs:/dev/ad0s1a
ad0s1: type 0xa5, start 63, end = 2503871, size 2503809 : OK
start_init: trying /sbin/init
sbp0:0:0 LOGIN
sbp: alloc 1 xfer
fwohci0: maxdesc: 3
dbdump err ch = 0 cmd = 0x02682821
sbp0:0:0 login: len 16, ID 0, cmd 0000fffff0100000, recon_hold 0
sbp0:0:0 sbp_busy_timeout
Current DB 0
ch = 0
 Current OP   KEY INT BR   len     Addr   Depend Stat: Cnt
02682880 OUTL ST2 ALL ALL    16 00000000 02682900 8412:2b0d RUN,ACTIVE, ack pend(12)
0x00824100 0xffc0ffff 0xf0000210 0x0f000002
sbp0:0:0 sbp_agent_reset
Current DB 0
ch = 0
 Current OP   KEY INT BR   len     Addr   Depend Stat: Cnt
02682900 OUTL ST2 ALL ALL    16 00000000 02682980 8412:2b3c RUN,ACTIVE, ack pend(12)
0x00824500 0xffc0ffff 0xf0100004 0x0f000000
sbp0:0:0 sbp_do_attach

    [ then I disconnect it ...]

fwohci0: BUS reset
sbp_post_busreset
fwohci0: node_id=0xc800ffc0, gen=3, CYCLEMASTER mode
firewire0: 1 nodes, maxhop <= 0, cable IRM = 0 (me)
fwohci0: fw_set_bus_manager: 0->0 (loop=0)
firewire0: bus manager 0 (me)
send phy_config root_node=-1 gap_count=5
fwohci0: start AT DMA status=12
Current DB 0
ch = 0
 Current OP   KEY INT BR   len     Addr   Depend Stat: Cnt
02682980 OUTL ST2 ALL ALL    12 00000000 02682a00 8411:3b95 RUN,ACTIVE, ack complete(11)
0x000000e0 0x00450000 0xffbaffff 0x00000000
bus_explore done
sbp_post_explore (sbp_cold=1)
sbp_post_explore: EUI:0010b920003dbcb3 not attached, state=3.
sbp0:0:0 lost target
fwohci0: BUS reset
sbp_post_busreset
fwohci0: node_id=0x8800ffc0, gen=5, non CYCLEMASTER mode
firewire0: 2 nodes, maxhop <= 1, cable IRM = 0 (me)
fwohci0: fw_set_bus_manager: 0->0 (loop=0)
firewire0: root node is not cycle master capable
firewire0: bus manager 0 (me)
send phy_config root_node=0 gap_count=5
fwohci0: start AT DMA status=11
Current DB 0
ch = 0
 Current OP   KEY INT BR   len     Addr   Depend Stat: Cnt
02682a00 OUTL ST2 ALL ALL    12 00000000 02682a80 8411:be5c RUN,ACTIVE, ack complete(11)
0x000000e0 0x00c50000 0xff3affff 0x00000000
node1: explore addr=0x400
Current DB 0
ch = 0
 Current OP   KEY INT BR   len     Addr   Depend Stat: Cnt
02682a80 OUTL ST2 ALL ALL    12 00000000 02682b00 8412:c6b2 RUN,ACTIVE, ack pend(12)
0x00804940 0xffc1ffff 0xf0000400 0x00000000
node1: callback addr=0x400
node1: explore addr=0x40c
Current DB 0
ch = 0
 Current OP   KEY INT BR   len     Addr   Depend Stat: Cnt
02682b00 OUTL ST2 ALL ALL    12 00000000 02682b80 8412:c6e8 RUN,ACTIVE, ack pend(12)
0x00804d40 0xffc1ffff 0xf000040c 0x00000000
node1: callback addr=0x40c
node1: explore addr=0x410
Current DB 0
ch = 0
 Current OP   KEY INT BR   len     Addr   Depend Stat: Cnt
02682b80 OUTL ST2 ALL ALL    12 00000000 02682c00 8412:c71f RUN,ACTIVE, ack pend(12)
0x00805140 0xffc1ffff 0xf0000410 0x00000000
node1: callback addr=0x410
node1: eui64 is zero.
bus_explore done
sbp_post_explore (sbp_cold=0)
sbp_post_explore: EUI:0010b920003dbcb3 not attached, state=3.

    [ and I reconnect it ... ]

fwohci0: BUS reset
sbp_post_busreset
fwohci0: node_id=0xc800ffc1, gen=6, CYCLEMASTER mode
firewire0: 2 nodes, maxhop <= 1, cable IRM = 1 (me)
fwohci0: fw_set_bus_manager: 1->1 (loop=0)
firewire0: bus manager 1 (me)
send phy_config root_node=1 gap_count=5
fwohci0: start AT DMA status=12
Current DB 0
ch = 0
 Current OP   KEY INT BR   len     Addr   Depend Stat: Cnt
02682c00 OUTL ST2 ALL ALL    12 00000000 02682c80 8411:d66d RUN,ACTIVE, ack complete(11)
0x000000e0 0x01c50000 0xfe3affff 0x00000000
node0: explore addr=0x400
Current DB 0
ch = 0
 Current OP   KEY INT BR   len     Addr   Depend Stat: Cnt
02682c80 OUTL ST2 ALL ALL    12 00000000 02682d00 8412:de23 RUN,ACTIVE, ack pend(12)
0x00805540 0xffc0ffff 0xf0000400 0x00000000
node0: callback addr=0x400
node0: explore addr=0x40c
Current DB 0
ch = 0
 Current OP   KEY INT BR   len     Addr   Depend Stat: Cnt
02682d00 OUTL ST2 ALL ALL    12 00000000 02682d80 8412:de59 RUN,ACTIVE, ack pend(12)
0x00805940 0xffc0ffff 0xf000040c 0x00000000
node0: callback addr=0x40c
node0: explore addr=0x410
Current DB 0
ch = 0
 Current OP   KEY INT BR   len     Addr   Depend Stat: Cnt
02682d80 OUTL ST2 ALL ALL    12 00000000 02682e00 8412:de8e RUN,ACTIVE, ack pend(12)
0x00805d40 0xffc0ffff 0xf0000410 0x00000000
node0: callback addr=0x410
node0: explore addr=0x400
Current DB 0
ch = 0
 Current OP   KEY INT BR   len     Addr   Depend Stat: Cnt
02682e00 OUTL ST2 ALL ALL    12 00000000 02682e80 8412:dec5 RUN,ACTIVE, ack pend(12)
0x00806140 0xffc0ffff 0xf0000400 0x00000000
node0: callback addr=0x400
bus_explore done
sbp_post_explore (sbp_cold=0)
sbp_post_explore: EUI:0010b920003dbcb3 attached
sbp0:0:0 ordered:1 type:14 EUI:0010b920003dbcb3 node:0 speed:2 maxrec:0
sbp0:0:0 'Maxtor' '5000XT  v1.00.00' '010000'
sbp0:0:0 RECONNECT
dbdump err ch = 0 cmd = 0x02682ea1
sbp0:0:0 reconnect failed
sbp0:0:0 LOGIN
dbdump err ch = 0 cmd = 0x02682f21
sbp0:0:0 login: len 16, ID 0, cmd 0000fffff0100000, recon_hold 0
sbp0:0:0 sbp_busy_timeout
Current DB 0
ch = 0
 Current OP   KEY INT BR   len     Addr   Depend Stat: Cnt
02682f80 OUTL ST2 ALL ALL    16 00000000 02683000 8412:1f31 RUN,ACTIVE, ack pend(12)
0x00826d00 0xffc0ffff 0xf0000210 0x0f000002
sbp0:0:0 sbp_agent_reset
Current DB 0
ch = 0
 Current OP   KEY INT BR   len     Addr   Depend Stat: Cnt
02683000 OUTL ST2 ALL ALL    16 00000000 02683080 8412:2022 RUN,ACTIVE, ack pend(12)
0x00827100 0xffc0ffff 0xf0100004 0x0f000000
sbp0:0:0 sbp_do_attach
sbp0:0:0 sbp_cam_scan_target
dbdump err ch = 0 cmd = 0x026830a1
dbdump err ch = 0 cmd = 0x02683121
sbp0:0:0 XPT_SCSI_IO: cmd: 1a 00 0a 00 14 00 00 00 00 00, flags: 0x40, 6b cmd/20b data/32b sense
sbp0:0:0 SCSI status 2 sfmt 0 valid 0 key 5 code 24 qlfr 0 len 3
(probe0:sbp0:0:0:0): MODE SENSE(06). CDB: 1a 0 a 0 14 0 
(probe0:sbp0:0:0:0): ILLEGAL REQUEST asc:24,0
(probe0:sbp0:0:0:0): Invalid field in CDB
dbdump err ch = 0 cmd = 0x026831a1
dbdump err ch = 0 cmd = 0x02683221
pass0 at sbp0 bus 0 target 0 lun 0
pass0: <Maxtor 5000XT  v1.00.00 0000> Fixed Simplified Direct Access SCSI-4 device 
pass0: Serial Number A80A06AE            
pass0: 50.000MB/s transfers, Tagged Queueing Enabled
Creating DISK da0
sbp0:0:0 sbp_cam_scan_lun
not sent yet tl=21
da0 at sbp0 bus 0 target 0 lun 0
da0: <Maxtor 5000XT  v1.00.00 0000> Fixed Simplified Direct Access SCSI-4 device 
da0: Serial Number A80A06AE            
da0: 50.000MB/s transfers, Tagged Queueing Enabled
da0: 239371MB (490232832 512 byte sectors: 255H 63S/T 30515C)
dbdump err ch = 0 cmd = 0x026832a1
already rcvd
dbdump err ch = 0 cmd = 0x02683321
dbdump err ch = 0 cmd = 0x026833a1
[snip normal operation of said drive]



Now I've turned my attention to a second card, which had given me problems
before.  It's a combination USB2/Firewire card, with a VIA6306 chip (mentioned
a few times in the firewire source files).

A side note, this combination card is a source of problems for me.  It
appears that I can successfully load USB modules with it (hacked, as
there seems to be an overcurrent problem), or perhaps firewire modules,
but as soon as I try to load the other functionality, the machine hangs
(on my development machine I can get into the debugger and see it's in a
doreti or doreti_foo) -- likewise at booting that never gets very far when
auto-loaded, most of the time.  I have sometimes had some success getting
into NetBSD or FreeBSD-current, but at least NetBSD wedges solid soon after.


The combi-card often does not even see the EUI of the device.  Instead,
it spits out:

firewire0: 2 nodes, maxhop <= 1, cable IRM = 1 (me)
fwohci0: fw_set_bus_manager: 1->1 (loop=0)
firewire0: bus manager 1 (me)
send phy_config root_node=1 gap_count=5
fwohci0: maxdesc: 2
fwohci0: start AT DMA status=0
node0: explore addr=0x400
sbp0: <SBP2/SCSI over firewire> on firewire0
sbp_attach (cold=0)
sbp_post_explore (sbp_cold=1)
firewire0: split transaction timeout dst=0xffc0 tl=0x1 state=2
           ^^^^^^^^^^^^^^^^^^^^^^^^^
node0: callback addr=0x400
node0: resp=60 addr=0x400
fw_xfer_free FWXF_START
bus_explore done
sbp_post_explore (sbp_cold=0)
probe failed for 1 node

Then nothing happens at any bus event.  This is with the modules loaded
after boot by hand.

However, this could just be a hardware problem, on this ten-year-old PC.
For when I moved the card to a different slot, and/or removed/exchanged
the ethernet card, and/or removed the sound card, now it does find the
attached drive, although it still needs a physical detach/attach after
boot to give me the drive as da0.

I haven't yet loaded the usb modules with the functioning firewire, to
see if it still wedges the machine.  Maybe later.


Thanks,
Barry Bouwsma



Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?200309241637.h8OGb1J02805>