G'Day Vincent,
On Wed, 23 Nov 2005, vincent wang wrote:
> Brendan Gregg wrote:
>
> >A cardbus wireless card detects ok, plumbs ok, has blinking lights ok,
> >appears to be furiously scanning - but never detects anything. A
> >"wificonfig -i ath0 scan" returns nothing, and syslog gets the following,
> >Nov 20 03:04:03 laptop genunix: [ID 765170 kern.warning] WARNING: ath:
> >ieee80211_end_scan(): no scan candidate
> >?
> >
> It's an interrupt routing problem.
> That message is usually because the ath driver recives no interrupt. (It
> can transmit packets but receives nothing.)
Thanks, looks like that is indeed the case. I've yet to get this to work,
but I've come up with some troubleshooting techniques that others in a
similar situation may find useful.
So, we believe interrupts for a cardbus wireless device are being routed
to the wrong driver. I've written a DTrace program to report who is
processing interrupt events. Firstly the output without the wireless card
plumbed,
# ./intr_call.d
Sampling... Hit Ctrl-C to end.
^C
MOD FUNC COUNT
pcplusmp apic_intr_enter 1
ehci ehci_intr 13
i8042 i8042_intr 86
ata ata_intr 250
uhci uhci_intr 443
unix cbe_fire 2807
And now with the wireless card plumbed and scanning,
# ./intr_call.d
Sampling... Hit Ctrl-C to end.
^C
MOD FUNC COUNT
i8042 i8042_intr 2
ata ata_intr 9
ehci ehci_intr 16
pcplusmp apic_intr_enter 192
unix cbe_fire 3333
uhci uhci_intr 747370
So "uhci" is picking up a flood of interrupts, but I'm certainly not doing
any additional USB activity. Looks like the cardbus events are being sent
to uhci by mistake.
The intr_call.d DTrace script is,
-----
#!/usr/sbin/dtrace -s
#pragma D option quiet
dtrace:::BEGIN
{
printf("Sampling... Hit Ctrl-C to end.\n");
}
sdt:::interrupt-start
{
self->ok = 1;
}
fbt:::
/self->ok/
{
@call[probemod,probefunc] = count();
self->ok = 0;
}
dtrace:::END
{
printf("%-16s %-16s %10s\n", "MOD", "FUNC", "COUNT");
printa("%-16s %-16s %...@10d\n", @call);
}
-----
...
trapstat is usually used to see that interrupts are being recieved,
# trapstat
trapstat: not implemented on i86pc
not to worry, this can also be fetched from Kstat,
# kstat -p cpu:0:intrstat:*count 10
cpu:0:intrstat:level-1-count 149491
cpu:0:intrstat:level-10-count 276268
cpu:0:intrstat:level-11-count 0
cpu:0:intrstat:level-12-count 0
cpu:0:intrstat:level-13-count 0
cpu:0:intrstat:level-14-count 278390
cpu:0:intrstat:level-15-count 0
cpu:0:intrstat:level-2-count 277924
cpu:0:intrstat:level-3-count 22342391
cpu:0:intrstat:level-4-count 16106
cpu:0:intrstat:level-5-count 23551
cpu:0:intrstat:level-6-count 0
cpu:0:intrstat:level-7-count 0
cpu:0:intrstat:level-8-count 0
cpu:0:intrstat:level-9-count 1
cpu:0:intrstat:level-1-count 150040
cpu:0:intrstat:level-10-count 277271
cpu:0:intrstat:level-11-count 0
cpu:0:intrstat:level-12-count 0
cpu:0:intrstat:level-13-count 0
cpu:0:intrstat:level-14-count 279393
cpu:0:intrstat:level-15-count 0
cpu:0:intrstat:level-2-count 278927
cpu:0:intrstat:level-3-count 25059704
cpu:0:intrstat:level-4-count 16112
cpu:0:intrstat:level-5-count 23567
cpu:0:intrstat:level-6-count 0
cpu:0:intrstat:level-7-count 0
cpu:0:intrstat:level-8-count 0
cpu:0:intrstat:level-9-count 1
^C
level-3-count climbs rapidly only when the wireless card is plumbed.
> We've seen this occasionally on some laptops. There can be two reasons:
> 1) The driver fails to register its interrupt correctly (The interrupt
> vector number could be wrongly translated)
This looks like the case. I haven't found a workaround yet. Anyone know
what intr_vector[] is on x86? (I don't mind an "mdb -kw" hack :).
I've had little joy with the hardware configuration manager. It often
suggests to add an "Unsupported ISA device" - which isn't in the list!
> 2) the interrupt is not in level-triggered mode.
>
> Please edit /etc/system and add :
> set pcic:pcic_debug=1
> set cardbus:cardbus_debug=1
> then reboot.
> /var/adm/messages may tell something about it.
>
> Vincent.
I've attached the /var/adm/messages data in case someone finds an
obvious error in the output.
cheers,
Brendan
[Sydney, Australia]
-----
Bus 3 Device 0 Function 0 Vendor 0x168c Device 0x0013 Name pci168c,13
pcplusmp: pciclass,0c0320 (ehci) instance 0 vector 0x77 ioapic 0x1 intin 0x17
is bound to cpu 0
pcplusmp: pciclass,0c0300 (uhci) instance 0 vector 0x74 ioapic 0x1 intin 0x10
is bound to cpu 0
pcplusmp: pciclass,0c0300 (uhci) instance #1 vector 0x75 ioapic 0x1 intin 0x13
is bound to cpu 0
pcplusmp: pciclass,0c0300 (uhci) instance #2 vector 0x76 ioapic 0x1 intin 0x12
is bound to cpu 0
pcic`_init: pci_dev_addr_low=0x10000000
pci0: host bridge:pci
pci0: calling fix_busrg_hstbrdge
pci0: setup_bus_ranges_for_host_bridge: used = db2fd018 usedpdip = db16cea8
pci0: calling fix_memrg_hstbrdge()
pci0: resource map for the host bridge:
NOTICE: ra_map_list_head=0xd46b6a90
type is pci_prefetchable_memory
type is pci_bus_number
dip is db16c008
range is 1 1
range is 3 fd
type is interrupt
type is memory
dip is db16c008
range is 10000000 d0000000
range is e0100400 400
range is e0100900 300
range is e0100e00 ff200
range is e0300000 7d00000
range is f8000000 6c00000
range is fec01000 f000
range is fec20000 e0000
range is fed03400 fcc00
range is fee01000 1ff000
type is io
dip is db16c008
range is 100 70
range is 178 78
range is 1f8 8
range is 210 166
range is 377 39
range is 3bc 4
range is 3e0 16
range is 3f7 d9
range is 4d2 12e
range is 610 f0
range is 710 f0
range is 810 4e8
range is d00 300
range is 1080 100
range is 11c0 640
range is 1808 8
range is 18a0 20
range is 1900 300
range is 1d00 300
range is 2080 380
range is 2500 b00
range is 4000 be00
range is fe02 1fe
pciclass,0607000: cb_expand_busrange:parent Secbus:2,Subbus:9
pciclass,0607000: pci-pci:db2fdc78 io port resoruce,0x30-0x30
pciclass,0607000: pci-pci:db2fdc78 mem range resoruce,0xe020-0xe020
NOTICE: pci-pci bridge resource map:
NOTICE: ra_map_list_head=0xd46b6a90
type is pci_prefetchable_memory
dip is db2fdc78
type is pci_bus_number
dip is db2fdc78
range is 3 7
type is interrupt
type is memory
dip is db2fdc78
range is e0200900 ff700
type is io
dip is db2fdc78
range is 3480 80
range is 3800 100
range is 3c00 100
pciclass,0607000: out expand_bus_range
pciclass,0607000: original ILINE = ff
pciclass,0607000: new ILINE = b
pciclass,0607000: PCI_CONF_BASE0 = 0x0
pciclass,0607000: cb_initbridge:updated reg for BAR0x10
pciclass,0607000: cb_initbridge:BASE register [0x10] asks for
[0xfffff000]=[0x1000](32)
pciclass,0607000: db2fd7f8 now under configuration
pciclass,0607000: cardbus_program_topbridge:rcount=2
pciclass,0607000: 32 addr = [0x0.e0210000] len [0x1000]
pcplusmp: pciclass,060700 (pcic) instance 0 vector 0xb ioapic 0x1 intin 0xb is
bound to cpu 0
pciclass,0607000: ////////////////////////////////////////
pciclass,0607000: SOCKET_EVENT = [0x0]
pciclass,0607000: SOCKET_MASK = [0x6]
pciclass,0607000: SOCKET_STATE = [0x30000820]
pciclass,0607000: ////////////////////////////////////////
Failed to lookup rootnex_modldrv
PCI-device: pci1179,ff00 at 4, pcic0
pcic0 is /pci at 0,0/pci8086,2448 at 1e/pci1179,ff00 at 4
pciclass,0607000: ........................................
pciclass,0607000: Pri Bus = [0x0]
pciclass,0607000: Sec Bus = [0x0]
pciclass,0607000: Sub Bus = [0x0]
pciclass,0607000: Cardbus Lattimer = [0x20]
pciclass,0607000: Cache Linesz= [0x8]
pciclass,0607000: Lattimer= [0x40]
pciclass,0607000: Command = [0x7]
pciclass,0607000: BAR0 = [0xe0210000]
pciclass,0607000: mem Base 0 = [0x0]
pciclass,0607000: mem Lim 0 = [0x0]
pciclass,0607000: mem Base 1 = [0x0]
pciclass,0607000: mem Lim 1 = [0x0]
pciclass,0607000: I/0 Base 0 = [0x0]
pciclass,0607000: I/O Lim 0 = [0x0]
pciclass,0607000: I/O Base 1 = [0x0]
pciclass,0607000: I/O Lim 1 = [0x0]
pciclass,0607000: Sec. Status = [0x200]
pciclass,0607000: Intr Line = [0xb]
pciclass,0607000: Intr Pin = [0x1]
pciclass,0607000: BrIdge CTL 0x3e = [0x7c0]
pciclass,0607000: Subsys Venid= [0x1179]
pciclass,0607000: Subsys ID = [0xff00]
pciclass,0607000: PCCARD I/F = [0x1]
pciclass,0607000: SYS CTL 0x80 = [0x4860d021]
pciclass,0607000: GEN CTL 0x86 = [0x0]
pciclass,0607000: G Purpos 0x88 = [0x0]
pciclass,0607000: MF-routing 0x8c = [0x2]
pciclass,0607000: Card CTL 0x91 = [0x0]
pciclass,0607000: DEV CTL 0x92 = [0x40]
pciclass,0607000: DIAG 0x93 = [0x40]
pciclass,0607000: ........................................
pcplusmp: pciclass,0c0010 (hci1394) instance 0 vector 0x0 ioapic 0x1 intin 0x14
is bound to cpu 0
Bus 3 Device 0 Function 0 Vendor 0x168c Device 0x0013 Name pci168c,13
pciclass,0607000: ........................................
pciclass,0607000: Pri Bus = [0x2]
pciclass,0607000: Sec Bus = [0x3]
pciclass,0607000: Sub Bus = [0x3]
pciclass,0607000: Cardbus Lattimer = [0x40]
pciclass,0607000: Cache Linesz= [0x10]
pciclass,0607000: Lattimer= [0x40]
pciclass,0607000: Command = [0x7]
pciclass,0607000: BAR0 = [0xe0210000]
pciclass,0607000: mem Base 0 = [0xe0220000]
pciclass,0607000: mem Lim 0 = [0xe022f000]
pciclass,0607000: mem Base 1 = [0x0]
pciclass,0607000: mem Lim 1 = [0x0]
pciclass,0607000: I/0 Base 0 = [0x0]
pciclass,0607000: I/O Lim 0 = [0x0]
pciclass,0607000: I/O Base 1 = [0x0]
pciclass,0607000: I/O Lim 1 = [0x0]
pciclass,0607000: Sec. Status = [0x200]
pciclass,0607000: Intr Line = [0xb]
pciclass,0607000: Intr Pin = [0x1]
pciclass,0607000: BrIdge CTL 0x3e = [0x420]
pciclass,0607000: Subsys Venid= [0x1179]
pciclass,0607000: Subsys ID = [0xff00]
pciclass,0607000: PCCARD I/F = [0x1]
pciclass,0607000: SYS CTL 0x80 = [0x4860f021]
pciclass,0607000: GEN CTL 0x86 = [0x0]
pciclass,0607000: G Purpos 0x88 = [0x0]
pciclass,0607000: MF-routing 0x8c = [0x2]
pciclass,0607000: Card CTL 0x91 = [0x0]
pciclass,0607000: DEV CTL 0x92 = [0x40]
pciclass,0607000: DIAG 0x93 = [0x40]
pciclass,0607000: ........................................
pci168c,130: ........................................
pci168c,130: VendorId = [0x168c]
pci168c,130: DeviceId = [0x13]
pci168c,130: Command = [0x6]
pci168c,130: CacheLineSz = [0x10]
pci168c,130: LatencyTmr = [0xa8]
pci168c,130: BAR0 = [0xe0220000]
pci168c,130: BAR1 = [0x0]
pci168c,130: BAR2 = [0x0]
pci168c,130: BAR3 = [0x0]
pci168c,130: BAR4 = [0x0]
pci168c,130: CIS = [0x5001]
pci168c,130: ILINE = [0xb]
pci168c,130: IPIN = [0x1]
device pciclass,030000 at 2(display#0) keeps up device sd at 0,0(sd#0), but the
latter is not power managed
