Lost connection to server, plenty of ath1 messages in the log

arabesc

arabesc

I have lost the network connection to my FreeBSD 10 server system.
# uname -imor
Code: 
FreeBSD 10.0-RELEASE-p9 amd64 GENERIC

There was no wired or wireless connection.
# ifconfig
Code: 
ath0: flags=8843<UP,BROADCAST,RUNNING,SIMPLEX,MULTICAST> metric 0 mtu 2290
    ether <mac_addr>
    nd6 options=21<PERFORMNUD,AUTO_LINKLOCAL>
    media: IEEE 802.11 Wireless Ethernet autoselect mode 11ng <hostap>
    status: running
ath1: flags=8843<UP,BROADCAST,RUNNING,SIMPLEX,MULTICAST> metric 0 mtu 2290
    ether <mac_addr>
    nd6 options=21<PERFORMNUD,AUTO_LINKLOCAL>
    media: IEEE 802.11 Wireless Ethernet autoselect mode 11na <hostap>
    status: running
igb0: flags=8843<UP,BROADCAST,RUNNING,SIMPLEX,MULTICAST> metric 0 mtu 1500
    options=403bb<RXCSUM,TXCSUM,VLAN_MTU,VLAN_HWTAGGING,JUMBO_MTU,VLAN_HWCSUM,TSO4,TSO6,VLAN_HWTSO>
    ether <mac_addr>
    inet6 <ipv6_addr> prefixlen 64 scopeid 0x3
    inet <ipv4_addr> netmask 0xfffff800 broadcast <ipv4_addr>
    nd6 options=23<PERFORMNUD,ACCEPT_RTADV,AUTO_LINKLOCAL>
    media: Ethernet autoselect (100baseTX <full-duplex>)
    status: active
igb1: flags=8943<UP,BROADCAST,RUNNING,PROMISC,SIMPLEX,MULTICAST> metric 0 mtu 1500
    options=400b8<VLAN_MTU,VLAN_HWTAGGING,JUMBO_MTU,VLAN_HWCSUM,VLAN_HWTSO>
    ether <mac_addr>
    inet6 <ipv6_addr> prefixlen 64 scopeid 0x4
    nd6 options=29<PERFORMNUD,IFDISABLED,AUTO_LINKLOCAL>
    media: Ethernet autoselect (1000baseT <full-duplex>)
    status: active
lo0: flags=8049<UP,LOOPBACK,RUNNING,MULTICAST> metric 0 mtu 16384
    options=600003<RXCSUM,TXCSUM,RXCSUM_IPV6,TXCSUM_IPV6>
    inet6 ::1 prefixlen 128
    inet6 fe80::1%lo0 prefixlen 64 scopeid 0x5
    inet 127.0.0.1 netmask 0xff000000
    nd6 options=21<PERFORMNUD,AUTO_LINKLOCAL>
bridge0: flags=8843<UP,BROADCAST,RUNNING,SIMPLEX,MULTICAST> metric 0 mtu 1500
    ether <mac_addr>
    inet 192.168.0.1 netmask 0xffffff00 broadcast 192.168.0.255
    nd6 options=9<PERFORMNUD,IFDISABLED>
    id 00:00:00:00:00:00 priority 32768 hellotime 2 fwddelay 15
    maxage 20 holdcnt 6 proto rstp maxaddr 2000 timeout 1200
    root id 00:00:00:00:00:00 priority 32768 ifcost 0 port 0
    member: wlan1 flags=143<LEARNING,DISCOVER,AUTOEDGE,AUTOPTP>
            ifmaxaddr 0 port 8 priority 128 path cost 22222
    member: wlan0 flags=143<LEARNING,DISCOVER,AUTOEDGE,AUTOPTP>
            ifmaxaddr 0 port 7 priority 128 path cost 22222
    member: igb1 flags=143<LEARNING,DISCOVER,AUTOEDGE,AUTOPTP>
            ifmaxaddr 0 port 4 priority 128 path cost 2000000
wlan0: flags=8943<UP,BROADCAST,RUNNING,PROMISC,SIMPLEX,MULTICAST> metric 0 mtu 1500
    ether <mac_addr>
    nd6 options=29<PERFORMNUD,IFDISABLED,AUTO_LINKLOCAL>
    media: IEEE 802.11 Wireless Ethernet autoselect mode 11ng <hostap>
    status: running
    ssid <1st wireless network name> channel 6 (2437 MHz 11g ht/40+) bssid 00:0e:8e:4b:b9:3c
    regdomain NONE indoor ecm authmode WPA1+WPA2/802.11i
    privacy MIXED deftxkey 3 TKIP 2:128-bit TKIP 3:128-bit txpower 30
    scanvalid 60 protmode CTS ampdulimit 64k ampdudensity 8 shortgi wme
    burst dtimperiod 1 -dfs
wlan1: flags=8943<UP,BROADCAST,RUNNING,PROMISC,SIMPLEX,MULTICAST> metric 0 mtu 1500
    ether <mac_addr>
    nd6 options=29<PERFORMNUD,IFDISABLED,AUTO_LINKLOCAL>
    media: IEEE 802.11 Wireless Ethernet autoselect mode 11na <hostap>
    status: running
    ssid <2nd wireless network name> channel 44 (5220 MHz 11a ht/20) bssid 00:0e:8e:4b:b9:3e
    regdomain NONE indoor ecm authmode WPA2/802.11i
    privacy MIXED deftxkey 3 AES-CCM 2:128-bit AES-CCM 3:128-bit
    txpower 17 mcastrate 6 mgmtrate 6 scanvalid 60 ampdulimit 64k
    ampdudensity 8 shortgi wme burst dtimperiod 1 -dfs
pflog0: flags=141<UP,RUNNING,PROMISC> metric 0 mtu 33160

There are a lot of messages all over the console screen and in /var/log/messages:
Code: 
kernel: ath1: ath_edma_recv_proc_queue: Q1: NULL bf?
kernel: ath1: ath_edma_rxbuf_alloc: nothing on rxbuf?!
kernel: ath1: ath_edma_rxfifo_alloc: Q1: alloc failed: i=0, nbufs=128?
kernel: ath1: ath_edma_recv_proc_queue: Q1: NULL bf?
kernel: ath1: ath_edma_rxbuf_alloc: nothing on rxbuf?!
kernel: ath1: ath_edma_rxfifo_alloc: Q1: alloc failed: i=0, nbufs=128?
...
kernel: ath1: ath_edma_recv_proc_queue: Q1: NULL bf?
kernel: ath1: ath_edma_rxbuf_alloc: nothing on rxbuf?!
kernel: ath1: ath_edma_rxfifo_alloc: Q1: alloc failed: i=0, nbufs=128?
Thousands of them. The system was unresponsive. Nothing seems to have worked. The DHCP server doesn't give leases. All that I could do was to remotely reboot the system by using the IPMI.

ath0 and ath1 are SparkLAN WPEA-127NI (Atheros 9390) 802.11abgn miniPCIe cards.

What could it be and how to debug it?
 
Last edited by a moderator:
Hi!

You can file bugs at https://bugs.FreeBSD.org/submit/.

It looks like it's supposed to be working (it's indicating 11n support was compiled in) but normally that error happens when there are not enough buffers or descriptors available. Try doing a sysctl dev.ath.0.txagg=1 and sysctl dev.ath.1.txagg=1; then grab the debug output from dmesg and put that in the bug submission.

I've fixed plenty of AR93xx related bugs in FreeBSD-HEAD. I don't think anyone has backported them to FreeBSD-10. Maybe trying FreeBSD-HEAD will resolve this. Otherwise, my normal Atheros offer still stands: if someone buys me the Atheros NIC and it's something that's mostly supported, I'll fix whatever issues I find.

Thanks!

-adrian
(WiFi maintainer)
 
adrian@ said:
Try doing a sysctl dev.ath.0.txagg=1 and sysctl dev.ath.1.txagg=1; then grab the debug output from dmesg and put that in the bug submission.
Click to expand...
It doesn't work for me:
Code: 
# sysctl dev.ath.0.txagg=1
dev.ath.0.txagg: 0 -> 0
 
Does it work reliably if you only use one band? I had issues with a 9380 with dual band and it works perfectly fine with only using one band. I've been meaning to try to replicate this a bit more and get some data for a bug report. Here are some of the symptoms I saw last time around. If you've already submitted a bug report, please post the link to it and I'll add what I can.

Shutdown over serial console:
Code: 
Stopping dhclient.
Mar 27 01:45:00 xju-rtr last message repeated 4 times
Mar 27 01:45:06 xju-rtr dhclient[1519]: short write: wanted 20 got 0 bytes
Mar 27 01:45:06 xju-rtr syslogd: sendto: No buffer space available
Mar 27 01:45:06 xju-rtr last message repeated 3 times
Mar 27 01:45:06 xju-rtr dhclient[1519]: exiting.
Mar 27 01:45:06 xju-rtr syslogd: sendto: No buffer space available
Mar 27 01:45:06 xju-rtr last message repeated 134 times
Mar 27 01:45:12 xju-rtr openvpn[1963]: RESOLVE: Cannot resolve host address: removed.dyndns.org: hostname nor servname provided, or not known
Mar 27 01:45:12 xju-rtr syslogd: sendto: No buffer space available
Mar 27 01:45:12 xju-rtr last message repeated 3 times
Mar 27 01:45:17 xju-rtr openvpn[1963]: RESOLVE: Cannot resolve host address: removed.dyndns.org: hostname nor servname provided, or not known
Mar 27 01:45:17 xju-rtr syslogd: sendto: No buffer space available
Mar 27 01:45:17 xju-rtr last message repeated 3 times
Mar 27 01:45:22 xju-rtr openvpn[1963]: RESOLVE: Cannot resolve host address: removed.dyndns.org: hostname nor servname provided, or not known
Mar 27 01:45:22 xju-rtr syslogd: sendto: No buffer space available
Mar 27 01:45:22 xju-rtr last message repeated 3 times
Mar 27 01:45:27 xju-rtr openvpn[1963]: RESOLVE: Cannot resolve host address: removed.dyndns.org: hostname nor servname provided, or not known
Mar 27 01:45:27 xju-rtr syslogd: sendto: No buffer space available

This one baffled me because this is my wired WAN interface and I would have thought this should have nothing to do with WiFi. Nonetheless, every time my wireless connection dropped and I logged in with a serial console I saw this.
Code: 
root@xju-rtr:~ # sysctl dev.em.3.link_irq
dev.em.3.link_irq: 684547
root@xju-rtr:~ # sysctl dev.em.3.link_irq
dev.em.3.link_irq: 684551
root@xju-rtr:~ # sysctl dev.em.3.link_irq
dev.em.3.link_irq: 684556

My top output was truncated because of the serial console, but my OpenVPN connection stayed locked in the *ath0_ state. Again confusing because that is going out over the WAN.
Code: 
root@xju-rtr:~ # top
last pid: 56208;  load averages:  0.32,  0.33,  0.32  up 0+17:16:46    18:57:28
36 processes:  1 running, 33 sleeping, 2 lock

Mem: 34M Active, 834M Inact, 389M Wired, 3960K Cache, 215M Buf, 719M Free
Swap:

  PID USERNAME       THR PRI NICE   SIZE    RES STATE   C   TIME    WCPU COMMAN
1098 root             1  20    0   167M 44156K pause   1  90:15   0.00% perl5.
  937 _openvpn         1  20    0 21584K  5552K *ath0_  1   2:58   0.00% openvp
 
junovitch said:
Does it work reliably if you only use one band?
Click to expand...
I have two wireless cards, each of them uses its own single band. Should I disable one of these two cards?

junovitch said:
If you've already put up a bug report, please put up the link to it and I'll add what I can.
Click to expand...
No, I didn't create a bug report yet. There's not enough data for it, it just doesn't work reliably for me.

junovitch said:
Run that command then run dmesg.
Click to expand...
I expect that dev.ath.0.txagg should be changed from 0 to 1, isn't it? I need time to reproduce this problem and collect data, it could take days. The problem may depend on the uptime duration, processed traffic or some state of the Moon, I don't know, it just happens from time to time. And when it happens it's hard to analyze, because server behaviour becomes unfriendly.
 
Sorry, I didn't look close enough at your first post regarding the two NICs. I can't exactly even remember what configuration I was using that caused me issues. I don't think I ever did dual band. I've started to play around with my configuration again to see if I can trigger the problem I saw and get a bug report in to document it. If it's already fixed in HEAD I'll try to apply and test the changes into 10-STABLE.

arabesc said:
I expect that dev.ath.0.txagg should be changed from 0 to 1, isn't it? I need time to reproduce this problem and collect data, it could take days. The problem may depend on the uptime duration, processed traffic or some state of the Moon, I don't know, it just happens from time to time. And when it happens it's hard to analyze, because server behaviour becomes unfriendly.
Click to expand...
The value doesn't change. It just triggers printing all the statistics to where they can be viewed with dmesg.
 
Last edited by a moderator:
What I have at the moment: I have routed all my wireless traffic through the old router (Asus RT-N66U) which was switched to the wireless-AP mode. I left the ath0 and ath1 interfaces grouped in the bridge along with igb1, these interfaces are up and running, but there are no clients for them, so they are almost idling. The system is stable now, its uptime is about a week. Before that the system became unstable in a few days.
 
I have built a custom 10.1 kernel with a bunch of branches from the head:
After that wireless connection is still unstable. I can join network but connection drops just in seconds. I don't see any error messages.

Excerpt from the /etc/rc.conf
Code: 
wlans_ath0="wlan0"
create_args_wlan0="wlanmode hostap mode 11ng channel 6:ht/20+ country GB regdomain etsi indoor bintval 400"
ifconfig_wlan0="HOSTAP"
#
wlans_ath1="wlan1"
create_args_wlan1="wlanmode hostap mode 11na channel 44:ht/40+ country GB regdomain etsi indoor bintval 400"
ifconfig_wlan1="HOSTAP"
#
ifconfig_igb1="-tso"
#
cloned_interfaces="bridge0"
ifconfig_bridge0="inet 192.168.0.1/24 addm igb1 addm wlan0 addm wlan1 up"
/etc/hostapd-wlan0.conf
Code: 
interface=wlan0
debug=1
ctrl_interface=/var/run/hostapd
ctrl_interface_group=wheel
ssid=2Gtest
wpa=3
wpa_passphrase=*********
wpa_key_mgmt=WPA-PSK
wpa_pairwise=CCMP
/etc/hostapd-wlan1.conf
Code: 
interface=wlan1
debug=1
ctrl_interface=/var/run/hostapd
ctrl_interface_group=wheel
ssid=5Gtest
wpa=2
wpa_passphrase=*********
wpa_key_mgmt=WPA-PSK
wpa_pairwise=CCMP
# sysctl dev.ath.1.txagg=1
# dmesg
Code: 
no tx bufs (empty list): 0
no tx bufs (was busy): 0
aggr single packet: 0
aggr single packet w/ BAW closed: 0
aggr non-baw packet: 0
aggr aggregate packet: 0
aggr single packet low hwq: 0
aggr single packet RTS aggr limited: 0
aggr sched, no work: 1081
0:  0  1:  0  2:  0  3:  0
4:  0  5:  0  6:  0  7:  0
8:  0  9:  0 10:  0 11:  0
12:  0 13:  0 14:  0 15:  0
16:  0 17:  0 18:  0 19:  0
20:  0 21:  0 22:  0 23:  0
24:  0 25:  0 26:  0 27:  0
28:  0 29:  0 30:  0 31:  0
32:  0 33:  0 34:  0 35:  0
36:  0 37:  0 38:  0 39:  0
40:  0 41:  0 42:  0 43:  0
44:  0 45:  0 46:  0 47:  0
48:  0 49:  0 50:  0 51:  0
52:  0 53:  0 54:  0 55:  0
56:  0 57:  0 58:  0 59:  0
60:  0 61:  0 62:  0 63:  0

HW TXQ 0: axq_depth=0, axq_aggr_depth=0, axq_fifo_depth=0, holdingbf=0
HW TXQ 1: axq_depth=0, axq_aggr_depth=0, axq_fifo_depth=0, holdingbf=0
HW TXQ 2: axq_depth=0, axq_aggr_depth=0, axq_fifo_depth=0, holdingbf=0
HW TXQ 3: axq_depth=0, axq_aggr_depth=0, axq_fifo_depth=0, holdingbf=0
HW TXQ 8: axq_depth=0, axq_aggr_depth=0, axq_fifo_depth=0, holdingbf=0
Total TX buffers: 512; Total TX buffers busy: 0 (512)
Total mgmt TX buffers: 32; Total mgmt TX buffers busy: 0
0: fifolen: 16/16; head=0; tail=0; m_pending=0, m_holdbf=0
1: fifolen: 128/128; head=11; tail=11; m_pending=0, m_holdbf=0
Total RX buffers in free list: 368 buffers
 
OK, there's something else going on. You have the right 11n options set it seems - it's allocated 512 RX/TX buffers correctly.

Mine looks like this:
Code: 
no tx bufs (empty list): 0
no tx bufs (was busy): 0
aggr single packet: 14289
aggr single packet w/ BAW closed: 0
aggr non-baw packet: 91
aggr aggregate packet: 18888
aggr single packet low hwq: 267727
aggr single packet RTS aggr limited: 0
aggr sched, no work: 67430
 0:  0  1:  0  2:  6346  3:  3120
 4:  2321  5:  1486  6:  1081  7:  889
 8:  684  9:  727 10:  449 11:  323
12:  187 13:  173 14:  149 15:  122
16:  103 17:  79 18:  139 19:  69
20:  65 21:  34 22:  27 23:  14
24:  25 25:  20 26:  17 27:  22
28:  19 29:  20 30:  15 31:  18
32:  145 33:  0 34:  0 35:  0
36:  0 37:  0 38:  0 39:  0
40:  0 41:  0 42:  0 43:  0
44:  0 45:  0 46:  0 47:  0
48:  0 49:  0 50:  0 51:  0
52:  0 53:  0 54:  0 55:  0
56:  0 57:  0 58:  0 59:  0
60:  0 61:  0 62:  0 63:  0

HW TXQ 0: axq_depth=0, axq_aggr_depth=0, axq_fifo_depth=0, holdingbf=0
HW TXQ 1: axq_depth=0, axq_aggr_depth=0, axq_fifo_depth=0, holdingbf=0
HW TXQ 2: axq_depth=0, axq_aggr_depth=0, axq_fifo_depth=0, holdingbf=0
HW TXQ 3: axq_depth=0, axq_aggr_depth=0, axq_fifo_depth=0, holdingbf=0
HW TXQ 8: axq_depth=0, axq_aggr_depth=0, axq_fifo_depth=0, holdingbf=0
Total TX buffers: 512; Total TX buffers busy: 0 (512)
Total mgmt TX buffers: 32; Total mgmt TX buffers busy: 0
0: fifolen: 16/16; head=2; tail=2; m_pending=0, m_holdbf=0
1: fifolen: 128/128; head=14; tail=14; m_pending=0, m_holdbf=0
Total RX buffers in free list: 368 buffers
It's a DB120 reference board with on-chip 2 GHz Wifi in the AR9344 chip, and AR9580 for 5GHz. I have some interrupt handling bugs to fix but the Wifi side is fine.

So, I'd next look at Wifi debugging. That's IEEE80211_DEBUG in the kernel, and the wlandebug(8) command.
Code: 
# wlandebug -?
usage: wlandebug [-d | -i device] [flags]
where flags are:
11n
debug
dumppkts
crypto
input
xrate
elemid
node
assoc
auth
scan
output
state
power
hwmp
dot1xsm
radius
raddump
mesh
wpa
acl
wme
superg
doth
inact
roam
rate
action
wds
ioctl
tdma
#
Try wlandebug +assoc +state +crypto and try associating. See what happens.
 
sysctl dev.ath.1.txagg=1
wlandebug +assoc +state +crypto
dmesg
Code: 
no tx bufs (empty list): 0
no tx bufs (was busy): 0
aggr single packet: 0
aggr single packet w/ BAW closed: 0
aggr non-baw packet: 0
aggr aggregate packet: 0
aggr single packet low hwq: 0
aggr single packet RTS aggr limited: 0
aggr sched, no work: 30018
 0:  0  1:  0  2:  0  3:  0
 4:  0  5:  0  6:  0  7:  0
 8:  0  9:  0 10:  0 11:  0
12:  0 13:  0 14:  0 15:  0
16:  0 17:  0 18:  0 19:  0
20:  0 21:  0 22:  0 23:  0
24:  0 25:  0 26:  0 27:  0
28:  0 29:  0 30:  0 31:  0
32:  0 33:  0 34:  0 35:  0
36:  0 37:  0 38:  0 39:  0
40:  0 41:  0 42:  0 43:  0
44:  0 45:  0 46:  0 47:  0
48:  0 49:  0 50:  0 51:  0
52:  0 53:  0 54:  0 55:  0
56:  0 57:  0 58:  0 59:  0
60:  0 61:  0 62:  0 63:  0

HW TXQ 0: axq_depth=0, axq_aggr_depth=0, axq_fifo_depth=0, holdingbf=0
HW TXQ 1: axq_depth=0, axq_aggr_depth=0, axq_fifo_depth=0, holdingbf=0
HW TXQ 2: axq_depth=0, axq_aggr_depth=0, axq_fifo_depth=0, holdingbf=0
HW TXQ 3: axq_depth=0, axq_aggr_depth=0, axq_fifo_depth=0, holdingbf=0
HW TXQ 8: axq_depth=0, axq_aggr_depth=0, axq_fifo_depth=0, holdingbf=0
Total TX buffers: 512; Total TX buffers busy: 0 (512)
Total mgmt TX buffers: 32; Total mgmt TX buffers busy: 0
0: fifolen: 16/16; head=0; tail=0; m_pending=0, m_holdbf=0
1: fifolen: 128/128; head=90; tail=90; m_pending=0, m_holdbf=0
Total RX buffers in free list: 368 buffers
wlan0: [00:0e:8e:4b:b9:3c] HT bss occupancy change: 0 sta, 0 ht, 0 ht40, non-HT sta present, HT protmode now 0x13
wlan0: [00:0e:8e:4b:b9:3c] HT bss occupancy change: 0 sta, 0 ht, 0 ht40, non-HT sta present, HT protmode now 0x11
...
wlan0: [00:0e:8e:4b:b9:3c] HT bss occupancy change: 0 sta, 0 ht, 0 ht40, non-HT sta present, HT protmode now 0x13
wlan0: [00:0e:8e:4b:b9:3c] HT bss occupancy change: 0 sta, 0 ht, 0 ht40, non-HT sta present, HT protmode now 0x11
wlan0: [00:26:08:e0:53:e0] RSN ie: mc 3/0 uc 3/0 key 2 caps 0x0
wlan0: [00:26:08:e0:53:e0] station associated at aid 1: short preamble, short slot time, QoS, HT20 (+AMPDU)
wlan0: [00:26:08:e0:53:e0] station unauthorize via MLME
wlan0: ieee80211_crypto_newkey: cipher 3 flags 0x87 keyix 5
wlan0: ieee80211_crypto_setkey: AES-CCM keyix 5 flags 0x107 mac ff:ff:ff:ff:ff:ff rsc 0 tsc 0 len 16
wlan0: ieee80211_crypto_newkey: cipher 3 flags 0x3 keyix 65535
wlan0: ieee80211_crypto_setkey: AES-CCM keyix 6 flags 0x103 mac 00:26:08:e0:53:e0 rsc 0 tsc 0 len 16
wlan0: [00:26:08:e0:53:e0] station authorize via MLME
wlan0: [00:26:08:e0:53:e0] station with aid 1 leaves
wlan0: _ieee80211_crypto_delkey: AES-CCM keyix 6 flags 0x103 rsc 0 tsc 97 len 16
wlan0: [00:26:08:e0:53:e0] RSN ie: mc 3/0 uc 3/0 key 2 caps 0x0
wlan0: [00:26:08:e0:53:e0] station associated at aid 1: short preamble, short slot time, QoS, HT20 (+AMPDU)
wlan0: [00:26:08:e0:53:e0] station unauthorize via MLME
wlan0: ieee80211_crypto_newkey: cipher 3 flags 0x3 keyix 65535
wlan0: ieee80211_crypto_setkey: AES-CCM keyix 6 flags 0x103 mac 00:26:08:e0:53:e0 rsc 0 tsc 0 len 16
wlan0: [00:26:08:e0:53:e0] station authorize via MLME
wlan0: [00:0e:8e:4b:b9:3c] HT bss occupancy change: 1 sta, 1 ht, 0 ht40, non-HT sta present, HT protmode now 0x13
wlan0: [00:0e:8e:4b:b9:3c] HT bss occupancy change: 1 sta, 1 ht, 0 ht40, non-HT sta present, HT protmode now 0x11
wlan0: [00:26:08:e0:53:e0] station with aid 1 leaves
wlan0: _ieee80211_crypto_delkey: AES-CCM keyix 6 flags 0x103 rsc 0 tsc 262 len 16
wlan0: [00:0e:8e:4b:b9:3c] HT bss occupancy change: 0 sta, 0 ht, 0 ht40, non-HT sta present, HT protmode now 0x13
wlan0: [00:0e:8e:4b:b9:3c] HT bss occupancy change: 0 sta, 0 ht, 0 ht40, non-HT sta present, HT protmode now 0x11
...
wlan0: [00:0e:8e:4b:b9:3c] HT bss occupancy change: 0 sta, 0 ht, 0 ht40, non-HT sta present, HT protmode now 0x13
wlan0: [00:0e:8e:4b:b9:3c] HT bss occupancy change: 0 sta, 0 ht, 0 ht40, non-HT sta present, HT protmode now 0x11
/var/log/hostapd.log
Code: 
Jan  8 18:02:03 sun hostapd: wlan1: WPA rekeying GTK
Jan  8 18:02:04 sun hostapd: wlan0: WPA rekeying GTK
Jan  8 18:02:29 sun hostapd: wlan1: STA 00:26:08:e0:53:e0 IEEE 802.11: associated
Jan  8 18:02:29 sun hostapd: wlan0: STA 00:26:08:e0:53:e0 IEEE 802.11: associated
Jan  8 18:02:29 sun hostapd: wlan0: STA 00:26:08:e0:53:e0 WPA: event 1 notification
Jan  8 18:02:29 sun hostapd: wlan0: STA 00:26:08:e0:53:e0 WPA: start authentication
Jan  8 18:02:29 sun hostapd: wlan0: STA 00:26:08:e0:53:e0 IEEE 802.1X: unauthorizing port
Jan  8 18:02:29 sun hostapd: wlan0: STA 00:26:08:e0:53:e0 WPA: sending 1/4 msg of 4-Way Handshake
Jan  8 18:02:29 sun hostapd: wlan0: STA 00:26:08:e0:53:e0 WPA: received EAPOL-Key frame (2/4 Pairwise)
Jan  8 18:02:29 sun hostapd: wlan0: STA 00:26:08:e0:53:e0 WPA: sending 3/4 msg of 4-Way Handshake
Jan  8 18:02:29 sun hostapd: wlan0: STA 00:26:08:e0:53:e0 WPA: received EAPOL-Key frame (4/4 Pairwise)
Jan  8 18:02:29 sun hostapd: wlan0: STA 00:26:08:e0:53:e0 IEEE 802.1X: authorizing port
Jan  8 18:02:29 sun hostapd: wlan0: STA 00:26:08:e0:53:e0 RADIUS: starting accounting session 54AE0390-00000002
Jan  8 18:02:29 sun hostapd: wlan0: STA 00:26:08:e0:53:e0 WPA: pairwise key handshake completed (RSN)
Jan  8 18:02:39 sun hostapd: wlan1: STA 00:26:08:e0:53:e0 IEEE 802.11: disassociated
Jan  8 18:02:39 sun hostapd: wlan0: STA 00:26:08:e0:53:e0 IEEE 802.11: disassociated
Jan  8 18:02:39 sun hostapd: wlan0: STA 00:26:08:e0:53:e0 WPA: event 2 notification
Jan  8 18:02:39 sun hostapd: wlan0: STA 00:26:08:e0:53:e0 IEEE 802.1X: unauthorizing port
Jan  8 18:02:40 sun hostapd: wlan0: STA 00:26:08:e0:53:e0 IEEE 802.11: associated
Jan  8 18:02:40 sun hostapd: wlan1: STA 00:26:08:e0:53:e0 IEEE 802.11: associated
Jan  8 18:02:40 sun hostapd: wlan0: STA 00:26:08:e0:53:e0 WPA: event 1 notification
Jan  8 18:02:40 sun hostapd: wlan0: STA 00:26:08:e0:53:e0 WPA: start authentication
Jan  8 18:02:40 sun hostapd: wlan0: STA 00:26:08:e0:53:e0 IEEE 802.1X: unauthorizing port
Jan  8 18:02:40 sun hostapd: wlan0: STA 00:26:08:e0:53:e0 WPA: sending 1/4 msg of 4-Way Handshake
Jan  8 18:02:40 sun hostapd: wlan0: STA 00:26:08:e0:53:e0 WPA: received EAPOL-Key frame (2/4 Pairwise)
Jan  8 18:02:40 sun hostapd: wlan0: STA 00:26:08:e0:53:e0 WPA: sending 3/4 msg of 4-Way Handshake
Jan  8 18:02:40 sun hostapd: wlan0: STA 00:26:08:e0:53:e0 WPA: received EAPOL-Key frame (4/4 Pairwise)
Jan  8 18:02:40 sun hostapd: wlan0: STA 00:26:08:e0:53:e0 IEEE 802.1X: authorizing port
Jan  8 18:02:40 sun hostapd: wlan0: STA 00:26:08:e0:53:e0 RADIUS: starting accounting session 54AE0390-00000003
Jan  8 18:02:40 sun hostapd: wlan0: STA 00:26:08:e0:53:e0 WPA: pairwise key handshake completed (RSN)
Jan  8 18:02:50 sun hostapd: wlan0: STA 00:26:08:e0:53:e0 IEEE 802.11: disassociated
Jan  8 18:02:50 sun hostapd: wlan1: STA 00:26:08:e0:53:e0 IEEE 802.11: disassociated
Jan  8 18:02:50 sun hostapd: wlan0: STA 00:26:08:e0:53:e0 WPA: event 2 notification
Jan  8 18:02:50 sun hostapd: wlan0: STA 00:26:08:e0:53:e0 IEEE 802.1X: unauthorizing port
 
I don't see any difference in behaviour.

/etc/hostapd-wlan0.conf
Code: 
interface=wlan0
debug=3
ctrl_interface=/var/run/hostapd
ctrl_interface_group=wheel
ssid=2Gtest
wpa=3
wpa_passphrase=*********
wpa_key_mgmt=WPA-PSK
wpa_pairwise=TKIP
sysctl dev.ath.0.txagg=1
wlandebug +assoc +state +crypto
dmesg
Code: 
no tx bufs (empty list): 0
no tx bufs (was busy): 0
aggr single packet: 0
aggr single packet w/ BAW closed: 0
aggr non-baw packet: 0
aggr aggregate packet: 0
aggr single packet low hwq: 0
aggr single packet RTS aggr limited: 0
aggr sched, no work: 156
 0:  0  1:  0  2:  0  3:  0
 4:  0  5:  0  6:  0  7:  0
 8:  0  9:  0 10:  0 11:  0
12:  0 13:  0 14:  0 15:  0
16:  0 17:  0 18:  0 19:  0
20:  0 21:  0 22:  0 23:  0
24:  0 25:  0 26:  0 27:  0
28:  0 29:  0 30:  0 31:  0
32:  0 33:  0 34:  0 35:  0
36:  0 37:  0 38:  0 39:  0
40:  0 41:  0 42:  0 43:  0
44:  0 45:  0 46:  0 47:  0
48:  0 49:  0 50:  0 51:  0
52:  0 53:  0 54:  0 55:  0
56:  0 57:  0 58:  0 59:  0
60:  0 61:  0 62:  0 63:  0

HW TXQ 0: axq_depth=0, axq_aggr_depth=0, axq_fifo_depth=0, holdingbf=0
HW TXQ 1: axq_depth=0, axq_aggr_depth=0, axq_fifo_depth=0, holdingbf=0
HW TXQ 2: axq_depth=0, axq_aggr_depth=0, axq_fifo_depth=0, holdingbf=0
HW TXQ 3: axq_depth=0, axq_aggr_depth=0, axq_fifo_depth=0, holdingbf=0
HW TXQ 8: axq_depth=0, axq_aggr_depth=0, axq_fifo_depth=0, holdingbf=0
Total TX buffers: 512; Total TX buffers busy: 0 (512)
Total mgmt TX buffers: 32; Total mgmt TX buffers busy: 0
0: fifolen: 16/16; head=0; tail=0; m_pending=0, m_holdbf=0
1: fifolen: 128/128; head=20; tail=20; m_pending=0, m_holdbf=0
Total RX buffers in free list: 368 buffers
wlan0: [00:26:08:e0:53:e0] RSN ie: mc 1/0 uc 1/0 key 2 caps 0x0
wlan0: [00:0e:8e:4b:b9:3c] HT bss occupancy change: 1 sta, 0 ht, 0 ht40, HT protmode now 0x13
wlan0: [00:26:08:e0:53:e0] station associated at aid 1: short preamble, short slot time, QoS
wlan0: [00:26:08:e0:53:e0] station unauthorize via MLME
wlan0: ieee80211_crypto_newkey: cipher 1 flags 0x87 keyix 4
wlan0: ieee80211_crypto_setkey: TKIP keyix 4 flags 0x107 mac ff:ff:ff:ff:ff:ff rsc 0 tsc 0 len 16
wlan0: ieee80211_crypto_newkey: cipher 1 flags 0x3 keyix 65535
wlan0: ieee80211_crypto_setkey: TKIP keyix 5 flags 0x103 mac 00:26:08:e0:53:e0 rsc 0 tsc 0 len 16
wlan0: [00:26:08:e0:53:e0] station authorize via MLME
wlan0: [00:26:08:e0:53:e0] station with aid 1 leaves
wlan0: [00:0e:8e:4b:b9:3c] HT bss occupancy change: 0 sta, 0 ht, 0 ht40, HT protmode now 0x0
wlan0: _ieee80211_crypto_delkey: TKIP keyix 5 flags 0x103 rsc 0 tsc 148 len 16
wlan0: [00:26:08:e0:53:e0] RSN ie: mc 1/0 uc 1/0 key 2 caps 0x0
wlan0: [00:0e:8e:4b:b9:3c] HT bss occupancy change: 1 sta, 0 ht, 0 ht40, HT protmode now 0x13
wlan0: [00:26:08:e0:53:e0] station associated at aid 1: short preamble, short slot time, QoS
wlan0: [00:26:08:e0:53:e0] station unauthorize via MLME
wlan0: ieee80211_crypto_newkey: cipher 1 flags 0x3 keyix 65535
wlan0: ieee80211_crypto_setkey: TKIP keyix 5 flags 0x103 mac 00:26:08:e0:53:e0 rsc 0 tsc 0 len 16
wlan0: [00:26:08:e0:53:e0] station authorize via MLME
wlan0: [00:26:08:e0:53:e0] station with aid 1 leaves
wlan0: [00:0e:8e:4b:b9:3c] HT bss occupancy change: 0 sta, 0 ht, 0 ht40, HT protmode now 0x0
wlan0: _ieee80211_crypto_delkey: TKIP keyix 5 flags 0x103 rsc 0 tsc 156 len 16
/var/log/hostapd.log
Code: 
Jan 14 02:54:59 sun hostapd: wlan0: STA 00:26:08:e0:53:e0 IEEE 802.11: associated
Jan 14 02:54:59 sun hostapd: wlan0: STA 00:26:08:e0:53:e0 WPA: event 1 notification
Jan 14 02:54:59 sun hostapd: wlan1: STA 00:26:08:e0:53:e0 IEEE 802.11: associated
Jan 14 02:54:59 sun hostapd: wlan0: STA 00:26:08:e0:53:e0 WPA: start authentication
Jan 14 02:54:59 sun hostapd: wlan0: STA 00:26:08:e0:53:e0 IEEE 802.1X: unauthorizing port
Jan 14 02:54:59 sun hostapd: wlan0: STA 00:26:08:e0:53:e0 WPA: sending 1/4 msg of 4-Way Handshake
Jan 14 02:54:59 sun hostapd: wlan0: STA 00:26:08:e0:53:e0 WPA: received EAPOL-Key frame (2/4 Pairwise)
Jan 14 02:54:59 sun hostapd: wlan0: STA 00:26:08:e0:53:e0 WPA: sending 3/4 msg of 4-Way Handshake
Jan 14 02:54:59 sun hostapd: wlan0: STA 00:26:08:e0:53:e0 WPA: received EAPOL-Key frame (4/4 Pairwise)
Jan 14 02:54:59 sun hostapd: wlan0: STA 00:26:08:e0:53:e0 IEEE 802.1X: authorizing port
Jan 14 02:54:59 sun hostapd: wlan0: STA 00:26:08:e0:53:e0 RADIUS: starting accounting session 54B5AF97-00000000
Jan 14 02:54:59 sun hostapd: wlan0: STA 00:26:08:e0:53:e0 WPA: pairwise key handshake completed (RSN)
Jan 14 02:55:09 sun hostapd: wlan1: STA 00:26:08:e0:53:e0 IEEE 802.11: disassociated
Jan 14 02:55:09 sun hostapd: wlan0: STA 00:26:08:e0:53:e0 IEEE 802.11: disassociated
Jan 14 02:55:09 sun hostapd: wlan0: STA 00:26:08:e0:53:e0 WPA: event 2 notification
Jan 14 02:55:09 sun hostapd: wlan0: STA 00:26:08:e0:53:e0 IEEE 802.1X: unauthorizing port
Jan 14 02:55:10 sun hostapd: wlan0: STA 00:26:08:e0:53:e0 IEEE 802.11: associated
Jan 14 02:55:10 sun hostapd: wlan0: STA 00:26:08:e0:53:e0 WPA: event 1 notification
Jan 14 02:55:10 sun hostapd: wlan1: STA 00:26:08:e0:53:e0 IEEE 802.11: associated
Jan 14 02:55:10 sun hostapd: wlan0: STA 00:26:08:e0:53:e0 WPA: start authentication
Jan 14 02:55:10 sun hostapd: wlan0: STA 00:26:08:e0:53:e0 IEEE 802.1X: unauthorizing port
Jan 14 02:55:10 sun hostapd: wlan0: STA 00:26:08:e0:53:e0 WPA: sending 1/4 msg of 4-Way Handshake
Jan 14 02:55:10 sun hostapd: wlan0: STA 00:26:08:e0:53:e0 WPA: received EAPOL-Key frame (2/4 Pairwise)
Jan 14 02:55:10 sun hostapd: wlan0: STA 00:26:08:e0:53:e0 WPA: sending 3/4 msg of 4-Way Handshake
Jan 14 02:55:10 sun hostapd: wlan0: STA 00:26:08:e0:53:e0 WPA: received EAPOL-Key frame (4/4 Pairwise)
Jan 14 02:55:10 sun hostapd: wlan0: STA 00:26:08:e0:53:e0 IEEE 802.1X: authorizing port
Jan 14 02:55:10 sun hostapd: wlan0: STA 00:26:08:e0:53:e0 RADIUS: starting accounting session 54B5AF97-00000001
Jan 14 02:55:10 sun hostapd: wlan0: STA 00:26:08:e0:53:e0 WPA: pairwise key handshake completed (RSN)
Jan 14 02:55:20 sun hostapd: wlan1: STA 00:26:08:e0:53:e0 IEEE 802.11: disassociated
Jan 14 02:55:20 sun hostapd: wlan0: STA 00:26:08:e0:53:e0 IEEE 802.11: disassociated
Jan 14 02:55:20 sun hostapd: wlan0: STA 00:26:08:e0:53:e0 WPA: event 2 notification
Jan 14 02:55:20 sun hostapd: wlan0: STA 00:26:08:e0:53:e0 IEEE 802.1X: unauthorizing port
 
You must log in or register to reply here.
Back
Top