On Wed, Mar 25, 2015 at 09:19:40PM -0700, Adrian Chadd wrote: > On 25 March 2015 at 19:21, David Wolfskill <da...@catwhisker.org> wrote: > > On Wed, Mar 25, 2015 at 06:17:48PM -0700, Adrian Chadd wrote: > >> Hi, > >> > >> I'm unfortunately too busy to really help you dig into it. > >> > >> I'd start by using tcpdump on wlan0 to see what's going on - see if > >> it's sending/receiving DHCP responses. > > > > Well, in head, it won't even associate, so I suspect that DHCP is a moot > > point. > > Ok, sysctl dev.iwn.0.debug=0x1, wlandebug +scan, and then start > wpa_supplicant. > > It should be reasonably obvious what's going on - if it can't see APs > or it can't transmit anything successfully, then at least I know where > to begin looking when I have spare time. > > I have a 5100 in my T400: > > iwn0@pci0:3:0:0: class=0x028000 card=0x12118086 chip=0x42378086 > rev=0x00 hdr=0x00 > vendor = 'Intel Corporation' > device = 'PRO/Wireless 5100 AGN [Shiloh] Network Connection' > class = network > > ....
Mine looks like:
iwn0@pci0:3:0:0: class=0x028000 card=0x13218086 chip=0x42328086 rev=0x00
hdr=0x00
vendor = 'Intel Corporation'
device = 'WiFi Link 5100'
class = network
I augmented /etc/src.conf:
g1-254(11.0-C)[8] cat /etc/src.conf
KERNCONF=CANARY
PORTS_MODULES=x11/nvidia-driver
WITHOUT_DEBUG_FILES=1
IWN_DEBUG=1
IEEE80211_DEBUG=1
g1-254(11.0-C)[9]
then re-built head:
FreeBSD g1-254.catwhisker.org 11.0-CURRENT FreeBSD 11.0-CURRENT #1551
r280680M/280683:1100067: Thu Mar 26 19:11:52 PDT 2015
r...@g1-254.catwhisker.org:/common/S4/obj/usr/src/sys/CANARY i386
I've attached the typescript (as before, but with a bit more success),
as well as a chunk of /var/log/messages that covers the period that the
typescript does.
Once again, though, it associated when I manually ran "service netif
start iwn0". Weird.
Peace,
david
--
David H. Wolfskill da...@catwhisker.org
Those who murder in the name of God or prophet are blasphemous cowards.
See http://www.catwhisker.org/~david/publickey.gpg for my public key.
Script started on Thu Mar 26 19:18:38 2015
root@g1-254:/tmp # ifc[K[K[Kuname -a
FreeBSD g1-254.catwhisker.org 11.0-CURRENT FreeBSD 11.0-CURRENT #1551
r280680M/280683:1100067: Thu Mar 26 19:11:52 PDT 2015
r...@g1-254.catwhisker.org:/common/S4/obj/usr/src/sys/CANARY i386
root@g1-254:/tmp # ifconfig wlan0
wlan0: flags=8843<UP,BROADCAST,RUNNING,SIMPLEX,MULTICAST> metric 0 mtu 1500
ether 34:e6:d7:3c:4a:93
nd6 options=29<PERFORMNUD,IFDISABLED,AUTO_LINKLOCAL>
media: IEEE 802.11 Wireless Ethernet autoselect (autoselect)
status: no carrier
ssid "" channel 11 (2462 MHz 11g)
country US authmode WPA1+WPA2/802.11i privacy ON deftxkey UNDEF
txpower 15 bmiss 10 scanvalid 60 bgscan bgscanintvl 300 bgscanidle 250
roam:rssi 7 roam:rate 5 protmode CTS wme roaming MANUAL
groups: wlan
root@g1-254:/tmp # ic[Kfconfig iwn0
iwn0: flags=8843<UP,BROADCAST,RUNNING,SIMPLEX,MULTICAST> metric 0 mtu 2290
ether 00:24:e8:b5:85:46
nd6 options=21<PERFORMNUD,AUTO_LINKLOCAL>
media: IEEE 802.11 Wireless Ethernet autoselect mode 11g
status: associated
root@g1-254:/tmp # echo "WiFi LED is blinking"
WiFi LED is blinking
root@g1-254:/tmp # pkill wpa_supplicant
root@g1-254:/tmp # ifconfig wlan0
wlan0: flags=8802<BROADCAST,SIMPLEX,MULTICAST> metric 0 mtu 1500
ether 34:e6:d7:3c:4a:93
nd6 options=29<PERFORMNUD,IFDISABLED,AUTO_LINKLOCAL>
media: IEEE 802.11 Wireless Ethernet autoselect (autoselect)
status: no carrier
ssid "" channel 149 (5745 MHz 11a ht/40+)
country US authmode WPA2/802.11i privacy OFF txpower 15 bmiss 10
mcastrate 6 mgmtrate 6 scanvalid 60 bgscan bgscanintvl 300
bgscanidle 250 roam:rssi 7 roam:rate 64 ampdulimit 8k -amsdutx amsdurx
shortgi wme
groups: wlan
root@g1-254:/tmp # ifconfig iwn0
iwn0: flags=8802<BROADCAST,SIMPLEX,MULTICAST> metric 0 mtu 2290
ether 00:24:e8:b5:85:46
nd6 options=21<PERFORMNUD,AUTO_LINKLOCAL>
media: IEEE 802.11 Wireless Ethernet autoselect (autoselect)
status: no carrier
root@g1-254:/tmp # echo "WiFiLED is dark"
WiFiLED is dark
root@g1-254:/tmp # sysctl dev.ien [K[Ke[Kwn net.wlan | sort
dev.iwn.%parent:
dev.iwn.0.%desc: Intel WiFi Link 5100
dev.iwn.0.%driver: iwn
dev.iwn.0.%location: pci0:3:0:0 handle=\_SB_.PCI0.RP03.PXSX
dev.iwn.0.%parent: pci3
dev.iwn.0.%pnpinfo: vendor=0x8086 device=0x4232 subvendor=0x8086
subdevice=0x1321 class=0x028000
dev.iwn.0.wake: 0
net.wlan.0.%parent: iwn0
net.wlan.0.ampdu_mintraffic_be: 64
net.wlan.0.ampdu_mintraffic_bk: 128
net.wlan.0.ampdu_mintraffic_vi: 32
net.wlan.0.ampdu_mintraffic_vo: 32
net.wlan.0.amrr_max_sucess_threshold: 15
net.wlan.0.amrr_min_sucess_threshold: 1
net.wlan.0.amrr_rate_interval: 500
net.wlan.0.bmiss_max: 2
net.wlan.0.debug: 0
net.wlan.0.driver_caps: 629203457
net.wlan.0.inact_auth: 180
net.wlan.0.inact_init: 30
net.wlan.0.inact_probe: 30
net.wlan.0.inact_run: 300
net.wlan.addba_backoff: 10000
net.wlan.addba_maxtries: 3
net.wlan.addba_timeout: 250
net.wlan.ampdu_age: 500
net.wlan.cac_timeout: 60
net.wlan.debug: 0
net.wlan.hwmp.inact: 5000
net.wlan.hwmp.maxpreq_retries: 3
net.wlan.hwmp.net_diameter_traversal_time: 512
net.wlan.hwmp.pathlifetime: 5000
net.wlan.hwmp.rannint: 1000
net.wlan.hwmp.rootconfint: 2000
net.wlan.hwmp.rootint: 2000
net.wlan.hwmp.roottimeout: 5000
net.wlan.hwmp.targetonly: 0
net.wlan.mesh.backofftimeout: 5000
net.wlan.mesh.confirmtimeout: 40
net.wlan.mesh.gateint: 10000
net.wlan.mesh.holdingtimeout: 40
net.wlan.mesh.maxholding: 2
net.wlan.mesh.maxretries: 2
net.wlan.mesh.retrytimeout: 40
net.wlan.nol_timeout: 1800
net.wlan.recv_bar: 1
root@g1-254:/tmp # sysctl dev.iwn.0.debug=0x1
sysctl: unknown oid 'dev.iwn.0.debug': No such file or directory
root@g1-254:/tmp # sysctl net.wlan.0.debug=1
net.wlan.0.debug: 0 -> 1
root@g1-254:/tmp # wlandebug +scan
net.wlan.0.debug: 0x1 => 0x200001<scan>
root@g1-254:/tmp # service netif stop wlan0 iwn0
wpa_supplicant not running? (check /var/run/wpa_supplicant/wlan0.pid).
Stopping Network: wlan0 iwn0.
ifconfig: interface wlan0 does not exist
iwn0: flags=8802<BROADCAST,SIMPLEX,MULTICAST> metric 0 mtu 2290
ether 00:24:e8:b5:85:46
nd6 options=21<PERFORMNUD,AUTO_LINKLOCAL>
media: IEEE 802.11 Wireless Ethernet autoselect (autoselect)
status: no carrier
root@g1-254:/tmp # service netif start iwn0
Starting wpa_supplicant.
Starting Network: iwn0.
iwn0: flags=8843<UP,BROADCAST,RUNNING,SIMPLEX,MULTICAST> metric 0 mtu 2290
ether 00:24:e8:b5:85:46
nd6 options=21<PERFORMNUD,AUTO_LINKLOCAL>
media: IEEE 802.11 Wireless Ethernet autoselect (autoselect)
status: no carrier
root@g1-254:/tmp # ifconfig iwn0
iwn0: flags=8843<UP,BROADCAST,RUNNING,SIMPLEX,MULTICAST> metric 0 mtu 2290
ether 00:24:e8:b5:85:46
nd6 options=21<PERFORMNUD,AUTO_LINKLOCAL>
media: IEEE 802.11 Wireless Ethernet autoselect mode 11ng
status: associated
root@g1-254:/tmp # ifconfig wlan0
wlan0: flags=8843<UP,BROADCAST,RUNNING,SIMPLEX,MULTICAST> metric 0 mtu 1500
ether 00:24:e8:b5:85:46
nd6 options=29<PERFORMNUD,IFDISABLED,AUTO_LINKLOCAL>
media: IEEE 802.11 Wireless Ethernet MCS mode 11ng
status: associated
ssid lmdhw-net channel 1 (2412 MHz 11g ht/20) bssid 04:18:d6:22:22:1f
country US authmode WPA2/802.11i privacy ON deftxkey UNDEF
AES-CCM 2:128-bit txpower 15 bmiss 10 scanvalid 60 bgscan
bgscanintvl 300 bgscanidle 250 roam:rssi 7 roam:rate 64 protmode CTS
ampdulimit 64k ampdudensity 8 -amsdutx amsdurx shortgi wme
roaming MANUAL
groups: wlan
root@g1-254:/tmp # ifconfig -v wlan0
wlan0: flags=8843<UP,BROADCAST,RUNNING,SIMPLEX,MULTICAST> metric 0 mtu 1500
ether 00:24:e8:b5:85:46
nd6 options=29<PERFORMNUD,IFDISABLED,AUTO_LINKLOCAL>
media: IEEE 802.11 Wireless Ethernet MCS mode 11ng
status: associated
ssid lmdhw-net channel 1 (2412 MHz 11g ht/20) bssid 04:18:d6:22:22:1f
regdomain 0 country US anywhere -ecm authmode WPA2/802.11i -wps -tsn
privacy ON deftxkey UNDEF
AES-CCM 2:128-bit powersavemode OFF powersavesleep 100 txpower 15
txpowmax 50.0 -dotd rtsthreshold 2346 fragthreshold 2346 bmiss 10
11a ucast NONE mgmt 6 Mb/s mcast 6 Mb/s maxretry 6
11b ucast NONE mgmt 1 Mb/s mcast 1 Mb/s maxretry 6
11g ucast NONE mgmt 1 Mb/s mcast 1 Mb/s maxretry 6
turboA ucast NONE mgmt 6 Mb/s mcast 6 Mb/s maxretry 6
turboG ucast NONE mgmt 1 Mb/s mcast 1 Mb/s maxretry 6
sturbo ucast NONE mgmt 6 Mb/s mcast 6 Mb/s maxretry 6
11na ucast NONE mgmt 12 MCS mcast 12 MCS maxretry 6
11ng ucast NONE mgmt 2 MCS mcast 2 MCS maxretry 6
half ucast NONE mgmt 3 Mb/s mcast 3 Mb/s maxretry 6
quarter ucast NONE mgmt 1 Mb/s mcast 1 Mb/s maxretry 6
scanvalid 60 bgscan bgscanintvl 300 bgscanidle 250
roam:11a rssi 7dBm rate 12 Mb/s
roam:11b rssi 7dBm rate 1 Mb/s
roam:11g rssi 7dBm rate 5 Mb/s
roam:turboA rssi 7dBm rate 12 Mb/s
roam:turboG rssi 7dBm rate 12 Mb/s
roam:sturbo rssi 7dBm rate 12 Mb/s
roam:11na rssi 7dBm MCS 1
roam:11ng rssi 7dBm MCS 1
roam:half rssi 7dBm rate 6 Mb/s
roam:quarter rssi 7dBm rate 3 Mb/s
-pureg protmode CTS ht htcompat ampdu ampdulimit 64k ampdudensity 8
-amsdutx amsdurx shortgi htprotmode RTSCTS -puren -smps -rifs wme
-burst -dwds roaming MANUAL bintval 100
AC_BE cwmin 4 cwmax 10 aifs 3 txopLimit 0 -acm ack
cwmin 4 cwmax 10 aifs 3 txopLimit 0 -acm
AC_BK cwmin 4 cwmax 10 aifs 7 txopLimit 0 -acm ack
cwmin 4 cwmax 10 aifs 7 txopLimit 0 -acm
AC_VI cwmin 3 cwmax 4 aifs 2 txopLimit 94 -acm ack
cwmin 3 cwmax 4 aifs 2 txopLimit 94 -acm
AC_VO cwmin 2 cwmax 3 aifs 2 txopLimit 47 -acm ack
cwmin 2 cwmax 3 aifs 2 txopLimit 47 -acm
groups: wlan
root@g1-254:/tmp # ^Dexit
Script done on Thu Mar 26 19:23:37 2015
Mar 26 19:17:38 kernel: ACPI Warning: \_SB_.PCI0.PEG0.PEGP._DSM: Argument #4 type mismatch - Found [Buffer], ACPI requires [Package] (20150204/nsarguments-97) Mar 26 19:17:38 wpa_supplicant[354]: wlan0: CTRL-EVENT-DISCONNECTED bssid=04:18:d6:22:22:1f reason=3 locally_generated=1 Mar 26 19:17:38 kernel: acquiring duplicate lock of same type: "os.lock_mtx" Mar 26 19:17:38 kernel: 1st os.lock_mtx @ nvidia_os.c:783 Mar 26 19:17:38 kernel: 2nd os.lock_mtx @ nvidia_os.c:783 Mar 26 19:17:38 kernel: KDB: stack backtrace: Mar 26 19:17:38 kernel: db_trace_self_wrapper(c1129408,eaf21c90,0,c14dace8,c14dacb8,...) at 0xc0531bca = db_trace_self_wrapper+0x2a/frame 0xf9e57488 Mar 26 19:17:38 kernel: kdb_backtrace(c112d361,c1e37fb1,c1e37f69,30f,cf0022b8,...) at 0xc0b5e2ed = kdb_backtrace+0x2d/frame 0xf9e574f0 Mar 26 19:17:38 kernel: witness_checkorder(d0cfb580,9,c1e37f69,30f,0,...) at 0xc0b7febe = witness_checkorder+0xd2e/frame 0xf9e57544 Mar 26 19:17:38 kernel: __mtx_lock_flags(d0cfb590,0,c1e37f69,30f,d2797f58,...) at 0xc0b08259 = __mtx_lock_flags+0x99/frame 0xf9e57578 Mar 26 19:17:38 kernel: os_acquire_spinlock(d0cfb580,d27a1000,0,cfb1f400,c1b5c931,...) at 0xc1d857ac = os_acquire_spinlock+0x2c/frame 0xf9e57590 Mar 26 19:17:38 kernel: _nv012380rm(0,1,1873f,0,0,...) at 0xc1b61ad8 = _nv012380rm+0xc10/frame 0xd2797f58 Mar 26 19:17:39 kernel: ACPI Warning: \_SB_.PCI0.PEG0.PEGP._DSM: Argument #4 type mismatch - Found [Buffer], ACPI requires [Package] (20150204/nsarguments-97) Mar 26 19:17:40 wpa_supplicant[354]: wlan0: Trying to associate with 04:18:d6:22:22:1f (SSID='lmdhw-net' freq=2412 MHz) Mar 26 19:17:45 ntpd[1002]: time reset -0.383123 s Mar 26 19:17:50 wpa_supplicant[354]: wlan0: Authentication with 04:18:d6:22:22:1f timed out. Mar 26 19:17:50 wpa_supplicant[354]: wlan0: CTRL-EVENT-DISCONNECTED bssid=04:18:d6:22:22:1f reason=3 locally_generated=1 Mar 26 19:17:53 wpa_supplicant[354]: wlan0: Trying to associate with 04:18:d6:22:22:1f (SSID='lmdhw-net' freq=2412 MHz) Mar 26 19:18:03 wpa_supplicant[354]: wlan0: Authentication with 04:18:d6:22:22:1f timed out. Mar 26 19:18:03 wpa_supplicant[354]: wlan0: CTRL-EVENT-DISCONNECTED bssid=04:18:d6:22:22:1f reason=3 locally_generated=1 Mar 26 19:18:05 wpa_supplicant[354]: wlan0: Trying to associate with 04:18:d6:22:22:1f (SSID='lmdhw-net' freq=2412 MHz) Mar 26 19:18:09 kernel: battery1: battery initialization failed, giving up Mar 26 19:18:15 wpa_supplicant[354]: wlan0: Authentication with 04:18:d6:22:22:1f timed out. Mar 26 19:18:15 wpa_supplicant[354]: wlan0: CTRL-EVENT-DISCONNECTED bssid=04:18:d6:22:22:1f reason=3 locally_generated=1 Mar 26 19:18:17 wpa_supplicant[354]: wlan0: Trying to associate with 04:18:d6:22:22:1f (SSID='lmdhw-net' freq=2412 MHz) Mar 26 19:18:27 wpa_supplicant[354]: wlan0: Authentication with 04:18:d6:22:22:1f timed out. Mar 26 19:18:27 wpa_supplicant[354]: wlan0: CTRL-EVENT-DISCONNECTED bssid=04:18:d6:22:22:1f reason=3 locally_generated=1 Mar 26 19:18:30 wpa_supplicant[354]: wlan0: Trying to associate with 04:18:d6:22:22:1f (SSID='lmdhw-net' freq=2412 MHz) Mar 26 19:18:40 wpa_supplicant[354]: wlan0: Authentication with 04:18:d6:22:22:1f timed out. Mar 26 19:18:40 wpa_supplicant[354]: wlan0: CTRL-EVENT-DISCONNECTED bssid=04:18:d6:22:22:1f reason=3 locally_generated=1 Mar 26 19:18:42 wpa_supplicant[354]: wlan0: Trying to associate with 04:18:d6:22:22:1f (SSID='lmdhw-net' freq=2412 MHz) Mar 26 19:18:52 wpa_supplicant[354]: wlan0: Authentication with 04:18:d6:22:22:1f timed out. Mar 26 19:18:52 wpa_supplicant[354]: wlan0: CTRL-EVENT-DISCONNECTED bssid=04:18:d6:22:22:1f reason=3 locally_generated=1 Mar 26 19:18:55 wpa_supplicant[354]: wlan0: Trying to associate with 04:18:d6:22:22:1f (SSID='lmdhw-net' freq=2412 MHz) Mar 26 19:19:05 wpa_supplicant[354]: wlan0: Authentication with 04:18:d6:22:22:1f timed out. Mar 26 19:19:05 wpa_supplicant[354]: wlan0: CTRL-EVENT-DISCONNECTED bssid=04:18:d6:22:22:1f reason=3 locally_generated=1 Mar 26 19:19:07 wpa_supplicant[354]: wlan0: Trying to associate with 04:18:d6:22:22:1f (SSID='lmdhw-net' freq=2412 MHz) Mar 26 19:19:17 wpa_supplicant[354]: wlan0: Authentication with 04:18:d6:22:22:1f timed out. Mar 26 19:19:17 wpa_supplicant[354]: wlan0: CTRL-EVENT-DISCONNECTED bssid=04:18:d6:22:22:1f reason=3 locally_generated=1 Mar 26 19:19:19 wpa_supplicant[354]: wlan0: Trying to associate with 0a:18:d6:21:22:1f (SSID='lmdhw-net' freq=5745 MHz) Mar 26 19:19:29 wpa_supplicant[354]: wlan0: Authentication with 0a:18:d6:21:22:1f timed out. Mar 26 19:19:29 wpa_supplicant[354]: wlan0: CTRL-EVENT-DISCONNECTED bssid=0a:18:d6:21:22:1f reason=3 locally_generated=1 Mar 26 19:19:30 wpa_supplicant[354]: ioctl[SIOCS80211, op=26, val=0, arg_len=0]: Operation not supported Mar 26 19:19:30 wpa_supplicant[354]: ioctl[SIOCS80211, op=26, val=0, arg_len=0]: Operation not supported Mar 26 19:19:30 wpa_supplicant[354]: wlan0: CTRL-EVENT-TERMINATING Mar 26 19:22:44 kernel: if_delmulti_locked: detaching ifnet instance 0xd1c1d400 Mar 26 19:22:44 kernel: wlan0: ieee80211_swscan_cancel_scan: called; F_SCAN=0, vap=match, CANCEL=0 Mar 26 19:22:44 kernel: wlan0: ieee80211_swscan_cancel_scan: called; F_SCAN=0, vap=match, CANCEL=0 Mar 26 19:22:58 kernel: iwn0: iwn_read_firmware: ucode rev=0x08530501 Mar 26 19:22:58 kernel: wlan0: bpf attached Mar 26 19:22:58 kernel: wlan0: bpf attached Mar 26 19:22:58 kernel: wlan0: Ethernet address: 00:24:e8:b5:85:46 Mar 26 19:22:58 wpa_supplicant[1526]: Successfully initialized wpa_supplicant Mar 26 19:22:58 wpa_supplicant[1539]: Successfully initialized wpa_supplicant Mar 26 19:22:58 root: /etc/rc.d/wpa_supplicant: WARNING: failed to start wpa_supplicant Mar 26 19:23:00 wpa_supplicant[1540]: wlan0: Trying to associate with 04:18:d6:22:22:1f (SSID='lmdhw-net' freq=2412 MHz) Mar 26 19:23:00 kernel: wlan0: link state changed to UP Mar 26 19:23:00 wpa_supplicant[1540]: wlan0: Associated with 04:18:d6:22:22:1f Mar 26 19:23:01 wpa_supplicant[1540]: wlan0: WPA: Key negotiation completed with 04:18:d6:22:22:1f [PTK=CCMP GTK=CCMP] Mar 26 19:23:01 wpa_supplicant[1540]: wlan0: CTRL-EVENT-CONNECTED - Connection to 04:18:d6:22:22:1f completed [id=15 id_str=]
pgpwOGPwhynZ9.pgp
Description: PGP signature
