On Thu, 30 Jan 2003 14:41:59 +0900, Hidetoshi Shimokawa wrote
> Do you get timeout only for sbp0:0:0?
> Is the other drive still working?
>
> I have no problem with concurrent accesses with `iozone -s 102400m -r
> 1024k`.
...
> try some of the following:
>
> - fwcontorl -g 20
> - sysctl hw.firewire.sbp.max_speed=0
> - change SBP_QUEUE_LEN in sbp.c to 1 and rebuld module.
> - sysctl machdep.cpu_idle_hlt=0
> - sysctl debug.sbp_debug=1 and send me a dmesg.
with all of the above I get the attached dmesg soon after
setting up two concurrent iozones (one per disk):
--
Michael Reifenberger
cam: invalid value for tunable kern.cam.scsi_delay
Copyright (c) 1992-2003 The FreeBSD Project.
Copyright (c) 1979, 1980, 1983, 1986, 1988, 1989, 1991, 1992, 1993, 1994
The Regents of the University of California. All rights reserved.
FreeBSD 5.0-CURRENT #1: Sun Feb 2 12:02:16 CET 2003
root@nihil:/usr/src/sys/i386/compile/nihil
Preloaded elf kernel "/boot/kernel/kernel" at 0xc0556000.
Preloaded userconfig_script "/boot/kernel.conf" at 0xc05560a8.
Preloaded elf module "/boot/kernel/procfs.ko" at 0xc05560f8.
Preloaded elf module "/boot/kernel/pseudofs.ko" at 0xc05561a4.
Preloaded elf module "/boot/kernel/md.ko" at 0xc0556254.
Preloaded elf module "/boot/kernel/linux.ko" at 0xc05562fc.
Preloaded elf module "/boot/kernel/sysvshm.ko" at 0xc05563a8.
Preloaded elf module "/boot/kernel/sysvsem.ko" at 0xc0556454.
Preloaded elf module "/boot/kernel/sysvmsg.ko" at 0xc0556500.
Preloaded elf module "/boot/kernel/miibus.ko" at 0xc05565ac.
Preloaded elf module "/boot/kernel/if_dc.ko" at 0xc0556658.
Preloaded elf module "/boot/kernel/if_ed.ko" at 0xc0556704.
Preloaded elf module "/boot/kernel/if_ep.ko" at 0xc05567b0.
Preloaded elf module "/boot/kernel/if_fxp.ko" at 0xc055685c.
Preloaded elf module "/boot/kernel/snd_ich.ko" at 0xc0556908.
Preloaded elf module "/boot/kernel/snd_pcm.ko" at 0xc05569b4.
Preloaded elf module "/boot/kernel/usb.ko" at 0xc0556a60.
Preloaded elf module "/boot/kernel/ums.ko" at 0xc0556b08.
Preloaded elf module "/boot/kernel/umass.ko" at 0xc0556bb0.
Preloaded elf module "/boot/kernel/uscanner.ko" at 0xc0556c5c.
Preloaded elf module "/boot/kernel/linprocfs.ko" at 0xc0556d0c.
Preloaded elf module "/boot/kernel/radeon.ko" at 0xc0556dbc.
Preloaded elf module "/boot/kernel/aic.ko" at 0xc0556e68.
Preloaded elf module "/boot/kernel/nfsserver.ko" at 0xc0556f10.
Preloaded elf module "/boot/kernel/nfsclient.ko" at 0xc0556fc0.
Preloaded elf module "/boot/kernel/firewire.ko" at 0xc0557070.
Preloaded elf module "/boot/kernel/sbp.ko" at 0xc0557120.
Preloaded elf module "/boot/kernel/acpi.ko" at 0xc05571c8.
Timecounter "i8254" frequency 1193182 Hz
Timecounter "TSC" frequency 1198986811 Hz
CPU: Intel(R) Pentium(R) III Mobile CPU 1200MHz (1198.99-MHz 686-class CPU)
Origin = "GenuineIntel" Id = 0x6b1 Stepping = 1
Features=0x383f9ff<FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,MMX,FXSR,SSE>
real memory = 1073086464 (1023 MB)
avail memory = 1037746176 (989 MB)
Initializing GEOMetry subsystem
Pentium Pro MTRR support enabled
VESA: v2.0, 32704k memory, flags:0x1, mode table:0xc034f942 (1000022)
VESA: ATI MOBILITY RADEON
npx0: <math processor> on motherboard
npx0: INT 16 interface
acpi0: <IBM TP-1E > on motherboard
ACPI-0625: *** Info: GPE Block0 defined as GPE0 to GPE15
ACPI-0625: *** Info: GPE Block1 defined as GPE16 to GPE31
Using $PIR table, 14 entries at 0xc00fdeb0
ACPI-1287: *** Error: Method execution failed, AE_NOT_EXIST
ACPI-1287: *** Error: Method execution failed, AE_NOT_EXIST
ACPI-1287: *** Error: Method execution failed, AE_NOT_EXIST
ACPI-1287: *** Error: Method execution failed, AE_NOT_EXIST
ACPI-1287: *** Error: Method execution failed, AE_NOT_EXIST
ACPI-1287: *** Error: Method execution failed, AE_NOT_EXIST
ACPI-1287: *** Error: Method execution failed, AE_NOT_EXIST
ACPI-1287: *** Error: Method execution failed, AE_NOT_EXIST
ACPI-1287: *** Error: Method execution failed, AE_NOT_EXIST
ACPI-1287: *** Error: Method execution failed, AE_NOT_EXIST
ACPI-1287: *** Error: Method execution failed, AE_NOT_EXIST
ACPI-1287: *** Error: Method execution failed, AE_NOT_EXIST
ACPI-1287: *** Error: Method execution failed, AE_NOT_EXIST
ACPI-1287: *** Error: Method execution failed, AE_NOT_EXIST
ACPI-1287: *** Error: Method execution failed, AE_NOT_EXIST
ACPI-1287: *** Error: Method execution failed, AE_NOT_EXIST
ACPI-1287: *** Error: Method execution failed, AE_NOT_EXIST
acpi0: power button is handled as a fixed feature programming model.
Timecounter "ACPI-fast" frequency 3579545 Hz
ACPI-1287: *** Error: Method execution failed, AE_NOT_EXIST
ACPI-1287: *** Error: Method execution failed, AE_NOT_EXIST
ACPI-1287: *** Error: Method execution failed, AE_NOT_EXIST
ACPI-1287: *** Error: Method execution failed, AE_NOT_EXIST
ACPI-1287: *** Error: Method execution failed, AE_NOT_EXIST
ACPI-1287: *** Error: Method execution failed, AE_NOT_EXIST
ACPI-1287: *** Error: Method execution failed, AE_NOT_EXIST
ACPI-1287: *** Error: Method execution failed, AE_NOT_EXIST
ACPI-1287: *** Error: Method execution failed, AE_NOT_EXIST
ACPI-1287: *** Error: Method execution failed, AE_NOT_EXIST
ACPI-1287: *** Error: Method execution failed, AE_NOT_EXIST
ACPI-1287: *** Error: Method execution failed, AE_NOT_EXIST
ACPI-1287: *** Error: Method execution failed, AE_NOT_EXIST
ACPI-1287: *** Error: Method execution failed, AE_NOT_EXIST
ACPI-1287: *** Error: Method execution failed, AE_NOT_EXIST
acpi_timer0: <24-bit timer at 3.579545MHz> port 0x1008-0x100b on acpi0
acpi_cpu0: <CPU> on acpi0
acpi_tz0: <thermal zone> on acpi0
acpi_lid0: <Control Method Lid Switch> on acpi0
ACPI-1287: *** Error: Method execution failed, AE_NOT_EXIST
acpi_button0: <Sleep Button> on acpi0
ACPI-1287: *** Error: Method execution failed, AE_NOT_EXIST
pcib0: <ACPI Host-PCI bridge> port 0xcf8-0xcff on acpi0
pci0: <ACPI PCI bus> on pcib0
agp0: <Intel 82830 host to AGP bridge> mem 0xd0000000-0xdfffffff at device 0.0 on pci0
pcib1: <ACPI PCI-PCI bridge> at device 1.0 on pci0
pci1: <ACPI PCI bus> on pcib1
drm0: <ATI Radeon LY Mobility 6 (AGP)> port 0x3000-0x30ff mem
0xc0100000-0xc010ffff,0xe0000000-0xe7ffffff irq 11 at device 0.0 on pci1
info: [drm] AGP at 0xd0000000 256MB
info: [drm] Initialized radeon 1.1.1 20010405 on minor 0
uhci0: <Intel 82801CA/CAM (ICH3) USB controller USB-A> port 0x1800-0x181f irq 11 at
device 29.0 on pci0
usb0: <Intel 82801CA/CAM (ICH3) USB controller USB-A> on uhci0
usb0: USB revision 1.0
uhub0: Intel UHCI root hub, class 9/0, rev 1.00/1.00, addr 1
uhub0: 2 ports with 2 removable, self powered
uhci1: <Intel 82801CA/CAM (ICH3) USB controller USB-B> port 0x1820-0x183f irq 11 at
device 29.1 on pci0
usb1: <Intel 82801CA/CAM (ICH3) USB controller USB-B> on uhci1
usb1: USB revision 1.0
uhub1: Intel UHCI root hub, class 9/0, rev 1.00/1.00, addr 1
uhub1: 2 ports with 2 removable, self powered
ums0: Logitech USB-PS/2 Optical Mouse, rev 2.00/11.00, addr 2, iclass 3/1
ums0: 3 buttons and Z dir.
uhci2: <Intel 82801CA/CAM (ICH3) USB controller USB-C> port 0x1840-0x185f irq 11 at
device 29.2 on pci0
usb2: <Intel 82801CA/CAM (ICH3) USB controller USB-C> on uhci2
usb2: USB revision 1.0
uhub2: Intel UHCI root hub, class 9/0, rev 1.00/1.00, addr 1
uhub2: 2 ports with 2 removable, self powered
pcib2: <ACPI PCI-PCI bridge> at device 30.0 on pci0
pci2: <ACPI PCI bus> on pcib2
cbb0: <RF5C478 PCI-CardBus Bridge> mem 0x50000000-0x50000fff irq 11 at device 0.0 on
pci2
start (50000000) < sc->membase (c0200000)
start (50000000) < sc->pmembase (e8000000)
cardbus0: <CardBus bus> on cbb0
pccard0: <16-bit PCCard bus> on cbb0
cbb0: cbb_power: CARD_VCC_0V and CARD_VPP_0V [44]
cbb1: <RF5C478 PCI-CardBus Bridge> mem 0x50100000-0x50100fff irq 11 at device 0.1 on
pci2
start (50100000) < sc->membase (c0200000)
start (50100000) < sc->pmembase (e8000000)
cardbus1: <CardBus bus> on cbb1
pccard1: <16-bit PCCard bus> on cbb1
cbb1: cbb_power: CARD_VCC_0V and CARD_VPP_0V [44]
fwohci0: vendor=1180, dev=522
fwohci0: <1394 Open Host Controller Interface> mem 0xc0201000-0xc02017ff irq 11 at
device 0.2 on pci2
fwohci0: PCI bus latency was changing to 250.
fwohci0: OHCI version 1.0 (ROM=0)
fwohci0: No. of Isochronous channel is 4.
fwohci0: EUI64 00:06:1b:02:01:00:0e:92
fwohci0: Phy 1394a available S400, 2 ports.
fwohci0: Link S400, max_rec 2048 bytes.
firewire0: <IEEE1394(FireWire) bus> on fwohci0
sbp0: <SBP2/SCSI over firewire> on firewire0
fxp0: <Intel Pro/100 Ethernet> port 0x8000-0x803f mem 0xc0200000-0xc0200fff irq 11 at
device 8.0 on pci2
fxp0: Ethernet address 00:d0:59:34:81:d3
inphy0: <i82562ET 10/100 media interface> on miibus0
inphy0: 10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, auto
isab0: <PCI-ISA bridge> at device 31.0 on pci0
isa0: <ISA bus> on isab0
atapci0: <Intel ICH3 ATA100 controller> port
0x1860-0x186f,0x374-0x377,0x170-0x177,0x3f4-0x3f7,0x1f0-0x1f7 at device 31.1 on pci0
ata0: at 0x1f0 irq 14 on atapci0
ata1: at 0x170 irq 15 on atapci0
ichsmb0: <Intel 82801CA (ICH3) SMBus controller> port 0x1880-0x189f irq 11 at device
31.3 on pci0
smbus0: <System Management Bus> on ichsmb0
smb0: <SMBus generic I/O> on smbus0
pcm0: <Intel 82801CA (ICH3)> port 0x18c0-0x18ff,0x1c00-0x1cff irq 11 at device 31.5 on
pci0
pci0: <simple comms> at device 31.6 (no driver attached)
atkbdc0: <Keyboard controller (i8042)> port 0x64,0x60 irq 1 on acpi0
atkbd0: <AT Keyboard> irq 1 on atkbdc0
psm0: <PS/2 Mouse> irq 12 on atkbdc0
psm0: model Generic PS/2 mouse, device ID 0
sio0 port 0x3f8-0x3ff irq 4 on acpi0
sio0: type 16550A
ppc0 port 0x7bc-0x7be,0x3bc-0x3c3 irq 7 drq 0 on acpi0
ppc0: Generic chipset (ECP/PS2/NIBBLE) in COMPATIBLE mode
ppi0: <Parallel I/O> on ppbus0
pps0: <Pulse per second Timing Interface> on ppbus0
sio1 port 0x2f8-0x2ff irq 3 drq 3 on acpi0
sio1: type 16550A
acpi_ec0: <embedded controller> port 0x66,0x62 on acpi0
acpi_cmbat0: <Control method Battery> on acpi0
acpi_cmbat1: <Control method Battery> on acpi0
acpi_acad0: <AC adapter> on acpi0
orm0: <Option ROMs> at iomem
0xe0000-0xeffff,0xdc000-0xdffff,0xd1000-0xd1fff,0xd0000-0xd0fff,0xc0000-0xcffff on isa0
sc0: <System console> on isa0
sc0: VGA <16 virtual consoles, flags=0x200>
vga0: <Generic ISA VGA> at port 0x3c0-0x3df iomem 0xa0000-0xbffff on isa0
Timecounters tick every 10.000 msec
IPsec: Initialized Security Association Processing.
fwohci0: BUS reset
fwohci0: node_id = 0xc800ffc0, CYCLEMASTER mode
firewire0: 1 nodes, maxhop <= 0, cable IRM = 0 (me)
system power profile changed to 'economy'
ad0: 45780MB <IC25T048ATDA05-0> [93015/16/63] at ata0-master UDMA100
ad1: 30520MB <IBM-DJSA-232> [62010/16/63] at ata1-master UDMA66
acd0: CD-RW <TOSHIBA DVD-ROM SD-R2002> at ata0-slave UDMA33
cd0 at ata0 bus 0 target 1 lun 0
cd0: <TOSHIBA DVD-ROM SD-R2002 1230> Removable CD-ROM SCSI-0 device
cd0: 33.000MB/s transfers
cd0: cd present [4098623 x 2048 byte records]
Mounting root from ufs:/dev/ad0s3a
system power profile changed to 'performance'
ACPI-0432: *** Error: Handler for [EmbeddedControl] returned AE_ERROR
ACPI-1287: *** Error: Method execution failed, AE_ERROR
ACPI-0432: *** Error: Handler for [EmbeddedControl] returned AE_ERROR
ACPI-1287: *** Error: Method execution failed, AE_ERROR
ACPI-1287: *** Error: Method execution failed, AE_AML_INTERNAL
ACPI-1287: *** Error: Method execution failed, AE_AML_INTERNAL
ACPI-1287: *** Error: Method execution failed, AE_AML_INTERNAL
ACPI-1287: *** Error: Method execution failed, AE_AML_INTERNAL
ACPI-1287: *** Error: Method execution failed, AE_AML_INTERNAL
ACPI-1287: *** Error: Method execution failed, AE_AML_INTERNAL
fwohci0: BUS reset
fwohci0: node_id = 0xc800ffc1, CYCLEMASTER mode
firewire0: 2 nodes, maxhop <= 1, cable IRM = 1 (me)
firewire0: New S400 device ID:0001d200e00d31f1
firewire0: Device SBP-II
sbp_post_explore: EUI:0001d200e00d31f1 spec=1 key=1.
target 0 lun 0 found
sbp0:0:0 LOGIN
sbp0:0:0 ordered:0 type:0 EUI:0001d200e00d31f1 node:0 speed:2 maxrec:5 new!
sbp0:0:0 'Oxford Semiconductor Ltd. ' 'OXFORD IDE Device LUN 0 ' '444133'
sbp0:0:0 login: len 16, ID 0, cmd 0000fffff0100000, recon_hold 0
sbp0:0:0 sbp_busy_timeout
sbp0:0:0 sbp_agent_reset
sbp0:0:0 sbp_do_attach
sbp0:0:0 sbp_cam_scan_lun
da0 at sbp0 bus 0 target 0 lun 0
da0: <Oxford S OXFORD IDE Devic 4133> Fixed Simplified Direct Access SCSI-4 device
da0: 50.000MB/s transfers
da0: 194481MB (398297088 512 byte sectors: 255H 63S/T 24792C)
fwohci0: BUS reset
fwohci0: node_id = 0xc800ffc2, CYCLEMASTER mode
firewire0: 3 nodes, maxhop <= 2, cable IRM = 2 (me)
firewire0: New S400 device ID:0001d200e00d2f5d
firewire0: Device SBP-II
sbp_post_explore: EUI:0001d200e00d2f5d spec=1 key=1.
target 1 lun 0 found
sbp0:1:0 LOGIN
sbp0:1:0 ordered:0 type:0 EUI:0001d200e00d2f5d node:0 speed:2 maxrec:5 new!
sbp0:1:0 'Oxford Semiconductor Ltd. ' 'OXFORD IDE Device LUN 0 ' '444133'
sbp_post_explore: EUI:0001d200e00d31f1 spec=1 key=1.
sbp0:0:0 RECONNECT
sbp0:0:0 ordered:0 type:0 EUI:0001d200e00d31f1 node:1 speed:2 maxrec:5
sbp0:0:0 'Oxford Semiconductor Ltd. ' 'OXFORD IDE Device LUN 0 ' '444133'
sbp0:0:0 reconnect: len 16, ID 0, cmd 0000fffff0100000
sbp0:1:0 login: len 16, ID 0, cmd 0000fffff0100000, recon_hold 0
sbp0:1:0 sbp_busy_timeout
sbp0:1:0 sbp_agent_reset
sbp0:1:0 sbp_do_attach
sbp0:1:0 sbp_cam_scan_lun
da1 at sbp0 bus 0 target 1 lun 0
da1: <Oxford S OXFORD IDE Devic 4133> Fixed Simplified Direct Access SCSI-4 device
da1: 50.000MB/s transfers
da1: 194481MB (398297088 512 byte sectors: 255H 63S/T 24792C)
sbp0:0:0 No ocb on the queue
sbp0:0:0 unordered execution order:1
sbp0:0:0 unordered execution order:1
sbp0:0:0 unordered execution order:1
sbp0:0:0 unordered execution order:1
sbp0:0:0 unordered execution order:1
sbp0:0:0 unordered execution order:1
sbp0:0:0 unordered execution order:1
sbp0:0:0 unordered execution order:1
sbp0:0:0 unordered execution order:1
sbp0:0:0 unordered execution order:1
sbp0:0:0 unordered execution order:1
sbp0:0:0 unordered execution order:1
sbp0:0:0 unordered execution order:1
sbp0:0:0 unordered execution order:1
sbp0:0:0 unordered execution order:1
sbp0:0:0 No ocb on the queue
sbp0:0:0 No ocb on the queue
sbp0:0:0 No ocb on the queue
sbp0:0:0 No ocb on the queue
sbp0:0:0 No ocb on the queue
sbp0:0:0 No ocb on the queue
sbp0:0:0 No ocb on the queue
sbp0:0:0 No ocb on the queue
sbp0:0:0 No ocb on the queue
sbp0:0:0 No ocb on the queue
sbp0:0:0 No ocb on the queue
sbp0:0:0 No ocb on the queue
sbp0:0:0 request timeout ... requeue
sbp0:0:0 sbp_abort_ocb 0xb
sbp0:0:0 XPT_SCSI_IO: cmd: 2a 00 00 12 05 fe 00 00 80 00, flags: 0x80, 10b cmd/65536b
data/32b sense
sbp0:0:0 sbp_abort_ocb 0xb
sbp0:0:0 XPT_SCSI_IO: cmd: 2a 00 00 12 0d fe 00 00 80 00, flags: 0x80, 10b cmd/65536b
data/32b sense
sbp0:0:0 sbp_abort_ocb 0xb
sbp0:0:0 XPT_SCSI_IO: cmd: 2a 00 00 12 0e 7e 00 00 80 00, flags: 0x80, 10b cmd/65536b
data/32b sense
sbp0:0:0 sbp_abort_ocb 0xb
sbp0:0:0 XPT_SCSI_IO: cmd: 2a 00 00 12 0e fe 00 00 80 00, flags: 0x80, 10b cmd/65536b
data/32b sense
sbp0:0:0 request timeout ... requeue
sbp0:1:0 request timeout ... requeue
sbp0:0:0 request timeout ... requeue
