Modify

Opened 18 months ago

Last modified 10 months ago

#21284 new defect

EA3500 (Audi Kirkwood) wifi unstable.

Reported by: anonymous Owned by: developers
Priority: normal Milestone: Designated Driver (Trunk)
Component: kernel Version: Trunk
Keywords: Cc:

Description

Wifi 2.4/5ghz unstable, disconnect/reconnect every 10-15 minutes. Speed of wifi very low.
Also, sysupgrade by command & luci not work.

Here are serial console output:

[16375.929051] ieee80211 phy1: Added a new stream for xx:xx:xx:xx:xx:xx 1
[16375.935673] ieee80211 phy1: Started stream for xx:xx:xx:xx:xx:xx 1
[16375.946894] ieee80211 phy1: Created a BA stream for xx:xx:xx:xx:xx:xx : tid 1
[16474.738511] ieee80211 phy1: Deleted BA stream index 0
[16474.743627] ieee80211 phy1: Remove stream for xx:xx:xx:xx:xx:xx 1
[16511.902198] ieee80211 phy1: Added a new stream for xx:xx:xx:xx:xx:xx 1
[16511.908813] ieee80211 phy1: Started stream for xx:xx:xx:xx:xx:xx 1
[16511.919923] ieee80211 phy1: Created a BA stream for xx:xx:xx:xx:xx:xx : tid 1
[17074.747541] ieee80211 phy1: Deleted BA stream index 0
[17074.752658] ieee80211 phy1: Remove stream for xx:xx:xx:xx:xx:xx 1
[17095.326113] ieee80211 phy1: tx rings drained
[50206.884605] ieee80211 phy0: Added a new stream for xx:xx:xx:xx:xx:xx 0
[50206.891217] ieee80211 phy0: Started stream for xx:xx:xx:xx:xx:xx 0
[50206.903656] ieee80211 phy0: Created a BA stream for xx:xx:xx:xx:xx:xx : tid 0
[50221.419890] ieee80211 phy0: Added a new stream for xx:xx:xx:xx:xx:xx 1
[50221.426513] ieee80211 phy0: Started stream for xx:xx:xx:xx:xx:xx 1
[50221.433460] ieee80211 phy0: tx rings drained
[50221.443587] ieee80211 phy0: Created a BA stream for xx:xx:xx:xx:xx:xx : tid 1
[50631.058364] ieee80211 phy0: Deleted BA stream index 0
[50631.063522] ieee80211 phy0: Deleted BA stream index 1
[50631.068850] ieee80211 phy0: Deleted BA stream index 0
[50631.073969] ieee80211 phy0: Remove stream for xx:xx:xx:xx:xx:xx 0
[50631.080495] ieee80211 phy0: Deleted BA stream index 1
[50631.085577] ieee80211 phy0: Remove stream for xx:xx:xx:xx:xx:xx 1
[50632.254497] ieee80211 phy0: Added a new stream for xx:xx:xx:xx:xx:xx 0
[50632.261109] ieee80211 phy0: Started stream for xx:xx:xx:xx:xx:xx 0
[50632.267739] ieee80211 phy0: Command BASTREAM error 0x1
[50633.353493] ieee80211 phy0: Created a BA stream for xx:xx:xx:xx:xx:xx : tid 0
[50785.175812] ieee80211 phy0: Added a new stream for xx:xx:xx:xx:xx:xx 1
[50785.182430] ieee80211 phy0: Started stream for xx:xx:xx:xx:xx:xx 1
[50785.189291] ieee80211 phy0: tx rings drained
[50785.198194] ieee80211 phy0: Created a BA stream for xx:xx:xx:xx:xx:xx : tid 1

Attachments (0)

Change History (41)

comment:1 Changed 18 months ago by anonymous

For the sysupgrade bit, what revision are you running? There was a bug in the very first supported builds before r45457 that made sysupgrade impossible. Check that 'fw_printenv' works.

comment:2 Changed 18 months ago by anonymous

excuse me, that should be r47457

comment:3 Changed 18 months ago by anonymous

Revision r47663.

Here fw_printenv output:

bootdelay=0
baudrate=115200
loads_echo=0
ipaddr=192.168.1.10
serverip=192.168.1.254
rootpath=/mnt/ARM_FS
netmask=255.255.255.0
run_diag=yes
stdin=serial
stdout=serial
stderr=serial
console=console=ttyS0,115200
badcount=0
bootbadcount=0
uenvbadcount=0
senvbadcount=0
buffbadcount=0
fs_bootargs=unused
mtdparts=mtdparts=nand_mtd:512k(uboot)ro,16k@512k(u_env),16k@528k(s_env),20m@2m(kernel),20m@2m(rootfs)fs,20m@2 2m(alt_kernel),20m@22m(alt_rootfs)fs,22m@42m(syscfg)
mfg_mtdparts=mtdparts=nand_mtd:512k(uboot)ro,16k@512k(u_env),16k@528k(s_env),20m@2m(kernel),20m@2m(rootfs)fs,2 0m@22m(alt_kernel),20m@22m(alt_rootfs)fs,20m@42m(mfg_kernel),20m@42m(mfg_rootfs)fs,2m@62m(syscfg)
mainlineLinux=no
enaMonExt=no
enaCpuStream=no
enaWrAllo=no
pexMode=RC
disL2Cache=no
setL2CacheWT=yes
disL2Prefetch=yes
enaICPref=yes
enaDCPref=yes
sata_dma_mode=yes
ethprime=egiga0
netbsd_en=no
vxworks_en=no
bootargs_root=root=/dev/nfs rw
fs_bootargs_root=root=/dev/mtdblock4 ro rootfstype=jffs2
alt_fs_bootargs_root=root=/dev/mtdblock6 ro rootfstype=jffs2
mfg_fs_bootargs_root=root=/dev/mtdblock8 ro rootfstype=jffs2
usb_fs_bootargs_root=root=/dev/sda1 rw rootfstype=ext2
bootargs_end=:::DB88FXX81:eth0:none
image_name=uImage
bootcmd=run nandboot
nfsboot=tftp 0x2000000 uImage; setenv bootargs $(console) $(mfg_mtdparts) $(bootargs_root) nfsroot=$(serverip) :$(rootpath) ip=$(ipaddr):$(serverip)$(bootargs_end); bootm 0x2000000;
nandboot=nand read.e 0x2000000 0x200000 0x300000; setenv bootargs $(console) $(mtdparts) $(fs_bootargs_root) s erial_number=$(sn) uuid=$(uuid) hw_version=$(hw) device_mac=$(mac) factory_date=$(date) wps_pin=$(wps); bootm 0x2000000;
altnandboot=nand read.e 0x2000000 0x1600000 0x300000; setenv bootargs $(console) $(mtdparts) $(alt_fs_bootargs _root) serial_number=$(sn) uuid=$(uuid) hw_version=$(hw) device_mac=$(mac) factory_date=$(date) wps_pin=$(wps) ; bootm 0x2000000;
mfgboot=nand read.e 0x2000000 0x2a00000 0x300000; setenv bootargs $(console) $(mfg_mtdparts) $(mfg_fs_bootargs _root) serial_number=$(sn) uuid=$(uuid) hw_version=$(hw) device_mac=$(mac) factory_date=$(date) wps_pin=$(wps) ; bootm 0x2000000;
usbboot=usb start;ext2load usb 0:1 2000000 /uImage; setenv bootargs $(console) $(mtdparts) $(usb_fs_bootargs_r oot) rootdelay=10; bootm 0x2000000;
standalone=fsload 0x2000000 $(image_name);setenv bootargs $(console) root=/dev/mtdblock0 rw ip=$(ipaddr):$(ser verip)$(bootargs_end) $(mvPhoneConfig); bootm 0x2000000;
lcd0_enable=0
lcd0_params=640x480-16@60
disaMvPnp=no
ethaddr=00:50:43:00:02:02
ethmtu=1500
eth1addr=00:50:43:00:02:02
eth1mtu=1500
mvPhoneConfig=mv_phone_config=dev[0]:fxs,dev[1]:fxo
mvNetConfig=mv_net_config=(00:11:88:0f:62:81,0:1:2:3),mtu=1500
usb0Mode=host
yuk_ethaddr=00:00:00:EE:51:81
nandEcc=1bit
netretry=no
rcvrip=169.254.100.100
loadaddr=0x02000000
autoload=no
image_multi=yes
enaAutoRecovery=yes
mtdparts_version=2
envsaved=yes
auto_recovery=yes

comment:4 Changed 18 months ago by anonymous

You're missing "boot_part" for some reason. How did you load this firmware and what were you running before?

You can try to set it manually:

fw_setenv boot_part 1

that should match your current bootcmd 'run nandboot'

comment:5 Changed 18 months ago by leitec

Some other values look a bit weird, too. ethaddr and eth1addr are the same. I haven't seen that yet on any EA3500's. Normally eth1addr is ethaddr + 1. I don't think that could affect the wifi or anything but I'm curious as to how this happened.

comment:6 Changed 18 months ago by anonymous

I have followed the wiki openwrt. Ok, I will try set bootpart & change eth1addr. Report soon.

comment:7 Changed 18 months ago by anonymous

Great, after add "bootpart 1", sysupgrade work well, thanks for suggestion !

I upgraded to r47670, reconfig router & see wifi will stable or unstable.

Tks.

comment:8 Changed 18 months ago by stephan.oelze@…

I am facing same behavior on ea4500. Had ea3500 tested also -same.
Surfing on iPad is really Bad. Webpage loading breaks ever second/third click.

Log shows same lines as in this ticket.

comment:9 Changed 18 months ago by anonymous

After about 18h testing, wifi still unstable:

[ 356.632570] ieee80211 phy0: Added a new stream for d0:22:be:ce:e5:62 1
[ 356.639200] ieee80211 phy0: Started stream for d0:22:be:ce:e5:62 1
[ 356.646041] ieee80211 phy0: tx rings drained
[ 356.697334] ieee80211 phy0: Created a BA stream for d0:22:be:ce:e5:62 : tid 1
[ 356.705646] ieee80211 phy0: Deleted BA stream index 0
[ 356.710775] ieee80211 phy0: Remove stream for d0:22:be:ce:e5:62 1
[ 607.800757] ieee80211 phy1: Added a new stream for d0:22:be:ce:e5:62 1
[ 607.807379] ieee80211 phy1: Started stream for d0:22:be:ce:e5:62 1
[ 607.818660] ieee80211 phy1: Created a BA stream for d0:22:be:ce:e5:62 : tid 1
[ 608.711340] ieee80211 phy1: Added a new stream for d0:22:be:ce:e5:62 0
[ 608.717958] ieee80211 phy1: Started stream for d0:22:be:ce:e5:62 0
[ 608.726972] ieee80211 phy1: Created a BA stream for d0:22:be:ce:e5:62 : tid 0
[ 627.826948] ieee80211 phy1: tx rings drained
[ 627.831406] ieee80211 phy1: Deleted BA stream index 1
[ 627.836613] ieee80211 phy1: Remove stream for d0:22:be:ce:e5:62 0
[ 627.843221] ieee80211 phy1: Deleted BA stream index 0
[ 627.848302] ieee80211 phy1: Remove stream for d0:22:be:ce:e5:62 1
[34755.804092] ieee80211 phy0: Started stream for 48:5a:3f:3f:99:f9 1
[34755.810409] ieee80211 phy0: Command BASTREAM error 0x1
[34756.820609] ieee80211 phy0: Command BASTREAM error 0x1
[34757.830624] ieee80211 phy0: Command BASTREAM error 0x1
[34758.840640] ieee80211 phy0: Command BASTREAM error 0x1
[34759.850650] ieee80211 phy0: Command BASTREAM error 0x1
[34760.860621] ieee80211 phy0: Stream for tid 1 busy after 5 attempts
[34760.866839] ieee80211 phy0: Remove stream for 48:5a:3f:3f:99:f9 1
[57936.583888] ieee80211 phy0: Deleted BA stream index 0
[57936.588976] ieee80211 phy0: Remove stream for 00:22:fa:c9:ec:be 1
[61768.543338] ieee80211 phy0: Started stream for 00:22:fa:c9:ec:be 0
[61768.555213] ieee80211 phy0: Created a BA stream for 00:22:fa:c9:ec:be : tid 0
[61797.232342] ieee80211 phy0: Deleted BA stream index 0
[61797.237803] ieee80211 phy0: Remove stream for 00:22:fa:c9:ec:be 0
[61797.850008] ieee80211 phy0: Added a new stream for 00:22:fa:c9:ec:be 0
[61797.856621] ieee80211 phy0: Started stream for 00:22:fa:c9:ec:be 0
[61797.863258] ieee80211 phy0: Command BASTREAM error 0x1
[61798.876026] ieee80211 phy0: Command BASTREAM error 0x1
[61799.886029] ieee80211 phy0: Command BASTREAM error 0x1
[61800.900234] ieee80211 phy0: Created a BA stream for 00:22:fa:c9:ec:be : tid 0
[61810.370663] ieee80211 phy0: Deleted BA stream index 0
[61810.375753] ieee80211 phy0: Remove stream for 00:22:fa:c9:ec:be 0
[61812.017030] ieee80211 phy0: Added a new stream for 00:22:fa:c9:ec:be 0
[61812.023621] ieee80211 phy0: Started stream for 00:22:fa:c9:ec:be 0
[61812.030377] ieee80211 phy0: Command BASTREAM error 0x1
[61813.036183] ieee80211 phy0: Command BASTREAM error 0x1
[61814.050587] ieee80211 phy0: Created a BA stream for 00:22:fa:c9:ec:be : tid 0
[61829.742939] ieee80211 phy0: Deleted BA stream index 0
[61829.748057] ieee80211 phy0: Remove stream for 00:22:fa:c9:ec:be 0
[61834.687894] ieee80211 phy0: Added a new stream for 00:22:fa:c9:ec:be 0
[61834.694489] ieee80211 phy0: Started stream for 00:22:fa:c9:ec:be 0
[61834.709227] ieee80211 phy0: Created a BA stream for 00:22:fa:c9:ec:be : tid 0
[61842.427391] ieee80211 phy0: Deleted BA stream index 0
[61842.432479] ieee80211 phy0: Remove stream for 00:22:fa:c9:ec:be 0

I tested with two device, one laptop (intel 5100agn) & one galaxy note 3.
Here are openwrt bootlog:

U-Boot 1.1.4 (Jan 2 2012 - 19:59:08) Marvell version: 3.5.9

U-Boot code: 00600000 -> 0067FFF0 BSS: -> 006CFB20

Soc: 88F6282 A1CPU running @ 800Mhz L2 running @ 400Mhz
SysClock = 400Mhz , TClock = 200Mhz

DRAM (DDR2) CAS Latency = 5 tRP = 6 tRAS = 18 tRCD=6
DRAM CS[0] base 0x00000000 size 64MB
DRAM Total size 64MB 16bit width
Addresses 8M - 0M are saved for the U-Boot usage.
Mem malloc Initialization (8M - 7M): Done
NAND:64 MB
Flash: 0 kB

CPU : Marvell Feroceon (Rev 1)
u_env Offset: 00080000
s_env Offset: 00084000

Streaming disabled
Write allocate disabled

Module 0 is RGMII

USB 0: host mode
PEX 0: PCI Express Root Complex Interface
PEX interface detected Link X1
PEX 1: PCI Express Root Complex Interface
PEX interface detected Link X1

Updating boot_count ... done

Net: egiga0 [PRIME], egiga1
Hit any key to stop autoboot: 0

NAND read: device 0 offset 0x1600000, size 0x300000

Reading data from 0x18ffe00 -- 100% complete.

3145728 bytes read: OK

## Booting image at 02000000 ...

Image Name: ARM OpenWrt Linux-3.18.23
Created: 2015-11-30 11:15:26 UTC
Image Type: ARM Linux Kernel Image (uncompressed)
Data Size: 1867470 Bytes = 1.8 MB
Load Address: 00008000
Entry Point: 00008000
Verifying Checksum ... OK

OK

Starting kernel ...

[ 0.000000] Booting Linux on physical CPU 0x0
[ 0.000000] Linux version 3.18.23 (thepeople@trabant) (gcc version 5.2.0 (OpenWrt GCC 5.2.0 r47670) ) #1 Mon Nov 30 12:15:02 CET 2015
[ 0.000000] CPU: Feroceon 88FR131 [56251311] revision 1 (ARMv5TE), cr=0005397f
[ 0.000000] CPU: VIVT data cache, VIVT instruction cache
[ 0.000000] Machine model: Linksys EA3500
[ 0.000000] Memory policy: Data cache writeback
[ 0.000000] Built 1 zonelists in Zone order, mobility grouping on. Total pages: 16256
[ 0.000000] Kernel command line: console=ttyS0,115200 mtdparts=nand_mtd:512k(uboot)ro,16k@512k(u_env),16k@528k(s_env),20m@2m(kernel),20m@2m(rootfs)fs,20m@22m(alt_kernel),20m@22m(alt_rootfs)fs,22m@42m(syscfg) root=/dev/mtdblock6 ro rootfstype=jffs2 serial_number=12C10609206650 uuid=6C95894C93CD9F81CB66BC4AA876D195 hw_version=RGWM-C5_0GA device_mac=C8:D7:19:17:72:42 factory_date=2012/09/24 wps_pin=21833489
[ 0.000000] PID hash table entries: 256 (order: -2, 1024 bytes)
[ 0.000000] Dentry cache hash table entries: 8192 (order: 3, 32768 bytes)
[ 0.000000] Inode-cache hash table entries: 4096 (order: 2, 16384 bytes)
[ 0.000000] Memory: 59524K/65536K available (3802K kernel code, 160K rwdata, 1016K rodata, 148K init, 198K bss, 6012K reserved)
[ 0.000000] Virtual kernel memory layout:
[ 0.000000] vector : 0xffff0000 - 0xffff1000 ( 4 kB)
[ 0.000000] fixmap : 0xffc00000 - 0xffe00000 (2048 kB)
[ 0.000000] vmalloc : 0xc4800000 - 0xff000000 ( 936 MB)
[ 0.000000] lowmem : 0xc0000000 - 0xc4000000 ( 64 MB)
[ 0.000000] modules : 0xbf000000 - 0xc0000000 ( 16 MB)
[ 0.000000] .text : 0xc0008000 - 0xc04bcd74 (4820 kB)
[ 0.000000] .init : 0xc04bd000 - 0xc04e2000 ( 148 kB)
[ 0.000000] .data : 0xc04e2000 - 0xc050a0e4 ( 161 kB)
[ 0.000000] .bss : 0xc050a0e4 - 0xc053b908 ( 199 kB)
[ 0.000000] NR_IRQS:16 nr_irqs:16 16
[ 0.000017] sched_clock: 32 bits at 200MHz, resolution 5ns, wraps every 21474836475ns
[ 0.000189] Calibrating delay loop... 795.44 BogoMIPS (lpj=3977216)
[ 0.040100] pid_max: default: 32768 minimum: 301
[ 0.040272] Mount-cache hash table entries: 1024 (order: 0, 4096 bytes)
[ 0.040295] Mountpoint-cache hash table entries: 1024 (order: 0, 4096 bytes)
[ 0.040868] CPU: Testing write buffer coherency: ok
[ 0.041244] Setting up static identity map for 0x11030 - 0x1106c
[ 0.041593] mvebu-soc-id: MVEBU SoC ID=0x6282, Rev=0x1
[ 0.043880] pinctrl core: initialized pinctrl subsystem
[ 0.044334] regulator-dummy: no parameters
[ 0.049093] NET: Registered protocol family 16
[ 0.049594] DMA: preallocated 256 KiB pool for atomic coherent allocations
[ 0.051228] cpuidle: using governor ladder
[ 0.051777] Feroceon L2: Enabling L2
[ 0.051825] Feroceon L2: Cache support initialised.
[ 0.052148] [Firmware Info]: /ocp@f1000000/ethernet-controller@72000/ethernet0-port@0: local-mac-address is not set
[ 0.052266] [Firmware Info]: /ocp@f1000000/ethernet-controller@76000/ethernet1-port@0: local-mac-address is not set
[ 0.062452] SCSI subsystem initialized
[ 0.062905] usbcore: registered new interface driver usbfs
[ 0.063015] usbcore: registered new interface driver hub
[ 0.063101] usbcore: registered new device driver usb
[ 0.064405] Switched to clocksource orion_clocksource
[ 0.065779] NET: Registered protocol family 2
[ 0.066731] TCP established hash table entries: 1024 (order: 0, 4096 bytes)
[ 0.066764] TCP bind hash table entries: 1024 (order: 0, 4096 bytes)
[ 0.066791] TCP: Hash tables configured (established 1024 bind 1024)
[ 0.066849] TCP: reno registered
[ 0.066864] UDP hash table entries: 256 (order: 0, 4096 bytes)
[ 0.066891] UDP-Lite hash table entries: 256 (order: 0, 4096 bytes)
[ 0.067119] NET: Registered protocol family 1
[ 0.068330] futex hash table entries: 256 (order: -1, 3072 bytes)
[ 0.069615] squashfs: version 4.0 (2009/01/31) Phillip Lougher
[ 0.069640] jffs2: version 2.2 (NAND) (SUMMARY) (LZMA) (RTIME) (CMODE_PRIORITY) (c) 2001-2006 Red Hat, Inc.
[ 0.069971] msgmni has been set to 116
[ 0.071867] io scheduler noop registered
[ 0.071891] io scheduler deadline registered (default)
[ 0.073435] kirkwood-pinctrl f1010000.pin-controller: registered pinctrl driver
[ 0.074177] irq: Cannot allocate irq_descs @ IRQ31, assuming pre-allocated
[ 0.074650] irq: Cannot allocate irq_descs @ IRQ63, assuming pre-allocated
[ 0.075472] mvebu-pcie mbus:pcie-controller: PCI host bridge to bus 0000:00
[ 0.075494] pci_bus 0000:00: root bus resource [io 0x1000-0xfffff]
[ 0.075512] pci_bus 0000:00: root bus resource [mem 0xe0000000-0xefffffff]
[ 0.075528] pci_bus 0000:00: root bus resource [bus 00-ff]
[ 0.076109] PCI: bus0: Fast back to back transfers disabled
[ 0.076129] pci 0000:00:01.0: bridge configuration invalid ([bus 00-00]), reconfiguring
[ 0.076148] pci 0000:00:02.0: bridge configuration invalid ([bus 00-00]), reconfiguring
[ 0.076769] PCI: bus1: Fast back to back transfers disabled
[ 0.077414] PCI: bus2: Fast back to back transfers disabled
[ 0.077565] pci 0000:00:01.0: BAR 8: assigned [mem 0xe0000000-0xe00fffff]
[ 0.077587] pci 0000:00:02.0: BAR 8: assigned [mem 0xe0100000-0xe01fffff]
[ 0.077610] pci 0000:01:00.0: BAR 0: assigned [mem 0xe0000000-0xe000ffff 64bit]
[ 0.077645] pci 0000:01:00.0: BAR 2: assigned [mem 0xe0010000-0xe001ffff 64bit]
[ 0.077675] pci 0000:00:01.0: PCI bridge to [bus 01]
[ 0.077693] pci 0000:00:01.0: bridge window [mem 0xe0000000-0xe00fffff]
[ 0.077718] pci 0000:02:00.0: BAR 0: assigned [mem 0xe0100000-0xe010ffff 64bit]
[ 0.077751] pci 0000:02:00.0: BAR 2: assigned [mem 0xe0110000-0xe011ffff 64bit]
[ 0.077780] pci 0000:00:02.0: PCI bridge to [bus 02]
[ 0.077798] pci 0000:00:02.0: bridge window [mem 0xe0100000-0xe01fffff]
[ 0.120346] Serial: 8250/16550 driver, 16 ports, IRQ sharing enabled
[ 0.124292] console [ttyS0] disabled
[ 0.124382] f1012000.serial: ttyS0 at MMIO 0xf1012000 (irq = 26, base_baud = 12500000) is a 16550A
[ 0.668268] console [ttyS0] enabled
[ 0.673240] nand: device found, Manufacturer ID: 0xad, Chip ID: 0x76
[ 0.679654] nand: Hynix NAND 64MiB 3,3V 8-bit
[ 0.684037] nand: 64MiB, SLC, page size: 512, OOB size: 16
[ 0.689576] Scanning device for bad blocks
[ 1.133275] mtd: bad character after partition (f)
[ 1.138141] 8 ofpart partitions found on MTD device orion_nand
[ 1.143997] Creating 8 MTD partitions on "orion_nand":
[ 1.149184] 0x000000000000-0x000000080000 : "u-boot"
[ 1.155156] 0x000000080000-0x000000084000 : "u_env"
[ 1.160848] 0x000000084000-0x000000088000 : "s_env"
[ 1.166578] 0x000000200000-0x000001600000 : "kernel1"
[ 1.172929] 0x000000490000-0x000001600000 : "rootfs1"
[ 1.179259] 0x000001600000-0x000002a00000 : "kernel2"
[ 1.185650] 0x000001890000-0x000002a00000 : "ubi"
[ 1.191602] 0x000002a00000-0x000004000000 : "syscfg"
[ 1.198611] libphy: orion_mdio_bus: probed
[ 1.202922] mv643xx_eth: MV-643xx 10/100/1000 ethernet driver version 1.4
[ 1.211425] mv643xx_eth_port mv643xx_eth_port.0 eth0: port 0 with MAC address 00:50:43:00:02:02
[ 1.220961] mv643xx_eth_port mv643xx_eth_port.1 eth1: port 0 with MAC address 00:50:43:00:02:03
[ 1.229791] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
[ 1.236380] ehci-pci: EHCI PCI platform driver
[ 1.240950] ehci-platform: EHCI generic platform driver
[ 1.246393] ehci-orion: EHCI orion driver
[ 1.250608] orion-ehci f1050000.ehci: EHCI Host Controller
[ 1.256178] orion-ehci f1050000.ehci: new USB bus registered, assigned bus number 1
[ 1.264024] orion-ehci f1050000.ehci: irq 29, io mem 0xf1050000
[ 1.285179] orion-ehci f1050000.ehci: USB 2.0 started, EHCI 1.00
[ 1.329237] hub 1-0:1.0: USB hub found
[ 1.333191] hub 1-0:1.0: 1 port detected
[ 1.337985] usbcore: registered new interface driver usb-storage
[ 1.345426] TCP: cubic registered
[ 1.348850] NET: Registered protocol family 10
[ 1.354785] NET: Registered protocol family 17
[ 1.359313] bridge: automatic filtering via arp/ip/ip6tables has been deprecated. Update your scripts to load br_netfilter if you need this.
[ 1.372037] Bridge firewalling registered
[ 1.376269] 8021q: 802.1Q VLAN Support v1.8
[ 1.382474] UBI: auto-attach mtd6
[ 1.385854] UBI: attaching mtd6 to ubi0
[ 1.513934] UBI: scanning is finished
[ 1.528360] UBI: attached mtd6 (name "ubi", size 17 MiB) to ubi0
[ 1.534437] UBI: PEB size: 16384 bytes (16 KiB), LEB size: 15872 bytes
[ 1.540993] UBI: min./max. I/O unit sizes: 512/512, sub-page size 256
[ 1.547482] UBI: VID header offset: 256 (aligned 256), data offset: 512
[ 1.554125] UBI: good PEBs: 1116, bad PEBs: 0, corrupted PEBs: 0
[ 1.560177] UBI: user volume: 2, internal volumes: 1, max. volumes count: 92
[ 1.567276] UBI: max/mean erase counter: 6/3, WL threshold: 4096, image sequence number: 501326687
[ 1.576292] UBI: available PEBs: 0, total reserved PEBs: 1116, PEBs reserved for bad PEB handling: 80
[ 1.586254] UBI: ubiblock0_0 created from ubi0:0(rootfs)
[ 1.591596] ubiblock: device ubiblock0_0 (rootfs) set to be root filesystem
[ 1.598871] UBI: background thread "ubi_bgt0d" started, PID 701
[ 1.608773] mvsw61xx 10.mvsw61xx: Found MV88E6171 at f1072004.mdio-bu:10
[ 1.615536] mvsw61xx 10.mvsw61xx: Using indirect addressing
[ 1.621236] drivers/rtc/hctosys.c: unable to open rtc device (rtc0)
[ 1.635661] VFS: Mounted root (squashfs filesystem) readonly on device 254:0.
[ 1.643276] Freeing unused kernel memory: 148K (c04bd000 - c04e2000)
[ 2.356771] init: Console is alive
[ 3.360945] init: - preinit -
[ 3.678352] random: procd urandom read with 30 bits of entropy available
Press the [f] key and hit [enter] to enter failsafe mode
Press the [1], [2], [3] or [4] key and hit [enter] to select the debug level
[ 6.811342] UBIFS: recovery needed
[ 6.815041] UBIFS: background thread "ubifs_bgt0_1" started, PID 850
[ 6.844694] UBIFS: recovery completed
[ 6.848469] UBIFS: mounted UBI device 0, volume 1, name "rootfs_data"
[ 6.854969] UBIFS: LEB size: 15872 bytes (15 KiB), min./max. I/O unit sizes: 512 bytes/512 bytes
[ 6.863798] UBIFS: FS size: 14205440 bytes (13 MiB, 895 LEBs), journal size 714240 bytes (0 MiB, 45 LEBs)
[ 6.873420] UBIFS: reserved for root: 670958 bytes (655 KiB)
[ 6.879128] UBIFS: media format: w4/r0 (latest is w4/r0), UUID B59C04E2-0A96-4C39-B2C8-4B67CF99494E, small LPT model
[ 6.895156] mount_root: switching to jffs2 overlay
[ 6.912776] procd: - early -
[ 8.150975] procd: - ubus -
[ 9.175300] procd: - init -
Please press Enter to activate this console.
[ 10.586782] ip6_tables: (C) 2000-2006 Netfilter Core Team
[ 10.606027] i2c /dev entries driver
[ 10.618909] Loading modules backported from Linux version master-2015-10-26-0-g28c26cb
[ 10.626906] Backport generated by backports.git backports-20150903-4-g12cf266
[ 10.642702] ip_tables: (C) 2000-2006 Netfilter Core Team
[ 10.654539] nf_conntrack version 0.5.0 (932 buckets, 3728 max)
[ 10.773827] xt_time: kernel timezone is -0000
[ 10.790786] cfg80211: World regulatory domain updated:
[ 10.795996] cfg80211: DFS Master region: unset
[ 10.800369] cfg80211: (start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp), (dfs_cac_time)
[ 10.810177] cfg80211: (2402000 KHz - 2472000 KHz @ 40000 KHz), (N/A, 2000 mBm), (N/A)
[ 10.818240] cfg80211: (2457000 KHz - 2482000 KHz @ 40000 KHz), (N/A, 2000 mBm), (N/A)
[ 10.826295] cfg80211: (2474000 KHz - 2494000 KHz @ 20000 KHz), (N/A, 2000 mBm), (N/A)
[ 10.834339] cfg80211: (5170000 KHz - 5250000 KHz @ 80000 KHz, 160000 KHz AUTO), (N/A, 2000 mBm), (N/A)
[ 10.843886] cfg80211: (5250000 KHz - 5330000 KHz @ 80000 KHz, 160000 KHz AUTO), (N/A, 2000 mBm), (0 s)
[ 10.853433] cfg80211: (5490000 KHz - 5730000 KHz @ 160000 KHz), (N/A, 2000 mBm), (0 s)
[ 10.861576] cfg80211: (5735000 KHz - 5835000 KHz @ 80000 KHz), (N/A, 2000 mBm), (N/A)
[ 10.869631] cfg80211: (57240000 KHz - 63720000 KHz @ 2160000 KHz), (N/A, 0 mBm), (N/A)
[ 10.976808] Marvell TOPDOG(R) 802.11 Wireless Network Driver version 0.13
[ 10.983657] pci 0000:00:01.0: enabling device (0140 -> 0142)
[ 11.972069] ieee80211 phy0: Command RF_ANTENNA error 0x2
[ 11.977455] ieee80211 phy0: failed to set # of RX antennas
[ 11.993318] ieee80211 phy0: Command RF_ANTENNA error 0x2
[ 11.998713] ieee80211 phy0: failed to set # of TX antennas
[ 12.004243] ieee80211 phy0: 88w8366 v48, c8d719177244, STA firmware 4.1.0.3
[ 12.014008] pci 0000:00:02.0: enabling device (0140 -> 0142)
[ 12.827430] ieee80211 phy1: Command RF_ANTENNA error 0x2
[ 12.832782] ieee80211 phy1: failed to set # of RX antennas
[ 12.847515] ieee80211 phy1: Command RF_ANTENNA error 0x2
[ 12.852867] ieee80211 phy1: failed to set # of TX antennas
[ 12.858429] ieee80211 phy1: 88w8366 v48, c8d719177246, STA firmware 4.1.0.3
[ 12.874782] PPP generic driver version 2.4.2
[ 12.895794] NET: Registered protocol family 24
[ 18.763942] mv643xx_eth_port mv643xx_eth_port.0 eth0: link up, 1000 Mb/s, full duplex, flow control disabled
[ 18.786938] device eth0 entered promiscuous mode
[ 18.797254] IPv6: ADDRCONF(NETDEV_UP): br-lan: link is not ready
[ 18.850206] mv643xx_eth_port mv643xx_eth_port.1 eth1: link up, 1000 Mb/s, full duplex, flow control disabled
[ 19.677949] cfg80211: Regulatory domain changed to country: US
[ 19.683816] cfg80211: DFS Master region: FCC
[ 19.688066] cfg80211: (start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp), (dfs_cac_time)
[ 19.697880] cfg80211: (2402000 KHz - 2472000 KHz @ 40000 KHz), (N/A, 3000 mBm), (N/A)
[ 19.705947] cfg80211: (5170000 KHz - 5250000 KHz @ 80000 KHz, 160000 KHz AUTO), (N/A, 2300 mBm), (N/A)
[ 19.715495] cfg80211: (5250000 KHz - 5330000 KHz @ 80000 KHz, 160000 KHz AUTO), (N/A, 2300 mBm), (0 s)
[ 19.725041] cfg80211: (5490000 KHz - 5730000 KHz @ 160000 KHz), (N/A, 2300 mBm), (0 s)
[ 19.733175] cfg80211: (5735000 KHz - 5835000 KHz @ 80000 KHz), (N/A, 3000 mBm), (N/A)
[ 19.741234] cfg80211: (57240000 KHz - 63720000 KHz @ 2160000 KHz), (N/A, 4000 mBm), (N/A)
[ 19.775544] br-lan: port 1(eth0) entered forwarding state
[ 19.781013] br-lan: port 1(eth0) entered forwarding state
[ 19.794468] IPv6: ADDRCONF(NETDEV_CHANGE): br-lan: link becomes ready
[ 21.774457] br-lan: port 1(eth0) entered forwarding state
[ 22.308888] ieee80211 phy0: 88w8366 v7, c8d719177244, AP firmware 5.2.8.17
[ 22.385479] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
[ 22.431030] device wlan0 entered promiscuous mode
[ 22.517451] 0000:02:00.0: unable to load firmware helper image
[ 22.523399] ieee80211 phy1: Cannot start firmware
[ 22.528230] ieee80211 phy1: Trying to reload the firmware again
[ 22.600166] random: nonblocking pool is initialized
[ 23.016669] ieee80211 phy1: 88w8366 v7, c8d719177246, AP firmware 5.2.8.17
[ 23.071158] IPv6: ADDRCONF(NETDEV_UP): wlan1: link is not ready
[ 23.080719] device wlan1 entered promiscuous mode
[ 23.085567] br-lan: port 3(wlan1) entered forwarding state
[ 23.091109] br-lan: port 3(wlan1) entered forwarding state
[ 23.394464] br-lan: port 3(wlan1) entered disabled state
[ 23.757510] IPv6: ADDRCONF(NETDEV_CHANGE): wlan1: link becomes ready
[ 23.764020] br-lan: port 3(wlan1) entered forwarding state
[ 23.769589] br-lan: port 3(wlan1) entered forwarding state
[ 23.970423] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
[ 23.976977] br-lan: port 2(wlan0) entered forwarding state
[ 23.982525] br-lan: port 2(wlan0) entered forwarding state
[ 25.764425] br-lan: port 3(wlan1) entered forwarding state
[ 25.974417] br-lan: port 2(wlan0) entered forwarding state

comment:10 Changed 18 months ago by leitec

Did it previously work for either of you and recently started working poorly, or are you new to OpenWrt on these models?

comment:11 Changed 18 months ago by anonymous

First time before, i'm install 15.05 final from oem stock, then router bricked. I follow wiki to try install Candyhouse project, and back to trunk.

comment:12 follow-ups: Changed 18 months ago by anonymous

I am experienced with openwrt (6 Years) and wrote the parts of wiki-ea4500. (how to install without serial). I am sure wifi setup is correct. Tested some settings ht20/ht40, lower txpower etc. Stock firmware works correctly for me.(just tested it one day)

There is "something" with the driver/firmware.
sta mode works correctly by the way, only saw this in ap mode

comment:13 in reply to: ↑ 12 Changed 18 months ago by leitec

Replying to anonymous:

I am experienced with openwrt (6 Years) and wrote the parts of wiki-ea4500. (how to install without serial). I am sure wifi setup is correct. Tested some settings ht20/ht40, lower txpower etc. Stock firmware works correctly for me.(just tested it one day)

There is "something" with the driver/firmware.
sta mode works correctly by the way, only saw this in ap mode

But did it previously work in AP mode in older revisions of OpenWrt? There aren't any recent changes to the mwl8k driver but there was a mac80211 update not that long ago.

comment:14 Changed 18 months ago by anonymous

I have this since day one.
Using this device since ~ 01.09.2015

comment:15 Changed 18 months ago by leitec

I see, thanks. That does predate the recent backport of mac80211.

mwl8k doesn't seem to be an actively-maintained driver so I'm not sure what the appropriate course of action would be. There are two OpenWrt-specific patches for it but I don't believe they are at all related.

comment:16 Changed 17 months ago by anonymous

I'm having this problem too, surfing internet is very annoying, I have to keep reloading every two or three times due connection lost errors...

My router is an e4200v2 and this problem started to happen recently.

comment:17 Changed 17 months ago by wooshcz@…

I'm having this problem as well. Currently on r48072 + EA3500. I'm able to provide logs and other information if needed.

comment:18 Changed 17 months ago by j.lancett@…

Can anyone say if this driver is fixable pleas. as i have one of thees routers the ea4500 i want to flash. If anyone is going to work on it i will flash to help test and giv logs. thanks

comment:19 Changed 17 months ago by julioviegas@…

I'm having the same problem too. Any news about this?

comment:20 Changed 14 months ago by anonymous

I'm having the same issue.
r49086

comment:21 follow-up: Changed 14 months ago by BenjaminH

Same issue here, 5ghz works fine. 2.4 Ghz fails. Relevant kernel log (most relevant starting 298.558331):

[    7.649446] Marvell TOPDOG(R) 802.11 Wireless Network Driver version 0.13
[    7.656340] pci 0000:00:01.0: enabling device (0140 -> 0142)
[    8.373708] ieee80211 phy0: Command RF_ANTENNA error 0x2
[    8.379095] ieee80211 phy0: failed to set # of RX antennas
[    8.384642] ieee80211 phy0: Command RF_ANTENNA error 0x2
[    8.390003] ieee80211 phy0: failed to set # of TX antennas
[    8.395546] ieee80211 phy0: 88w8366 v48, 20aa4b7e3281, STA firmware 4.1.0.3
[    8.406269] pci 0000:00:02.0: enabling device (0140 -> 0142)
[    9.066300] ieee80211 phy1: Command RF_ANTENNA error 0x2
[    9.071650] ieee80211 phy1: failed to set # of RX antennas
[    9.077224] ieee80211 phy1: Command RF_ANTENNA error 0x2
[    9.082567] ieee80211 phy1: failed to set # of TX antennas
[    9.088115] ieee80211 phy1: 88w8366 v48, 20aa4b7e3283, STA firmware 4.1.0.3
[   17.403926] ieee80211 phy1: 88w8366 v7, 20aa4b7e3283, AP firmware 5.2.8.17
[   17.452398] IPv6: ADDRCONF(NETDEV_UP): wlan1: link is not ready
[   17.459930] device wlan1 entered promiscuous mode
[   20.855368] IPv6: ADDRCONF(NETDEV_CHANGE): wlan1: link becomes ready
[  260.456672] ieee80211 phy1: tx rings drained
[  298.558331] 0000:01:00.0: unable to load firmware helper image
[  298.564274] ieee80211 phy0: Cannot start firmware
[  298.569109] ieee80211 phy0: Trying to reload the firmware again
[  299.036221] ieee80211 phy0: 88w8366 v7, 20aa4b7e3281, AP firmware 5.2.8.17
[  299.085116] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
[  299.089917] device wlan0 entered promiscuous mode
[  299.105871] device wlan0 left promiscuous mode
[  299.105971] br-lan: port 3(wlan0) entered disabled state

comment:22 in reply to: ↑ 21 Changed 14 months ago by BenjaminH

Forgot to add, I'm on r49114.
Replying to BenjaminH

comment:23 follow-up: Changed 14 months ago by anonymous

hmm... i have an ea4500 on r49096 since april 1st. radio seems stable on both 2.4ghz and 5ghz. i noticed sometimes i'm not able to enable 2.4Ghz radio via LuCI and had to manually create the wireless configuration. for now i'm staying with this build until there's a good reason for me to update. who is maintaining the mwl8k driver?

comment:24 in reply to: ↑ 23 Changed 14 months ago by BenjaminH

Replying to anonymous:

hmm... i have an ea4500 on r49096 since april 1st. radio seems stable on both 2.4ghz and 5ghz. i noticed sometimes i'm not able to enable 2.4Ghz radio via LuCI and had to manually create the wireless configuration. for now i'm staying with this build until there's a good reason for me to update. who is maintaining the mwl8k driver?

How did you create the configuration manually? Did you just set /etc/config/wireless or did you write the hostapd config in /tmp/run/hostapd-phy0.conf yourself? Either way, how exactly did you do it?

comment:25 follow-up: Changed 13 months ago by Lynx

Running r49166 on an ea4200v2. Had to manually

create the wireless configuration by editing /etc/conf/wireless. Added an explicit name for each 'wifi-iface' section and set the hwmode to '11g' for radio0.

comment:26 in reply to: ↑ 12 Changed 13 months ago by anonymous

Replying to anonymous:

I am experienced with openwrt (6 Years) and wrote the parts of wiki-ea4500. (how to install without serial). I am sure wifi setup is correct. Tested some settings ht20/ht40, lower txpower etc. Stock firmware works correctly for me.(just tested it one day)

There is "something" with the driver/firmware.
sta mode works correctly by the way, only saw this in ap mode

Maybe it is a firmware/driver issue. As you can see in the logs of other users, the version of AP firmware is 5.2.8.17. However, the latest EA3500 stock firmware includes AP firmware version 5.3.0.6.
Unfortunately, I'm not a programmer so I'm not able to adapt mac80211 to work with the stock AP firmware 5.3.0.6 or change the stock GPL wlan driver to work with OpenWrt.

comment:27 in reply to: ↑ 25 Changed 12 months ago by Kate6

Replying to Lynx:

Running r49166 on an ea4200v2. Had to manually

create the wireless configuration by editing /etc/conf/wireless. Added an explicit name for each 'wifi-iface' section and set the hwmode to '11g' for radio0.

Thank you for this!

Running r49377 on an ea3500. 2.4GHz radio wasn't enabling. After manually editing the configuration LuCI had left at /etc/config/wireless and changing hwmode from '11a' to '11g' the radio has enabled. Also seems to work if I put '11n' in that field so I've left it with that value.

Would this be a bug in LuCI or a bug in the wifi driver?

comment:28 Changed 12 months ago by lordgilman

The audi package was upgraded to kernel 4.4 on March 14th. I've upgraded to a trunk build that has the 4.4 kernel but I'm still experiencing the disconnects. :(

I also have multiple WiFi devices that regularly use this access point. One's a Nexus 4 and it works great, never gets these disconnects. The other two devices are Samsung Galaxy phones of different models and they both get the disconnects. Wondering if there's some corner case behavior those wireless chips are exposing here that the maintainers of the kernel driver didn't account for.

comment:29 follow-up: Changed 11 months ago by lm@…

Same here. Installed kirkwood audi from snapshot from 2016.06.14. Wifi disconnects every couple of seconds:

[95626.434003] ieee80211 phy0: Started stream for 00:21:6a:49:37:e6 0
[95626.445770] ieee80211 phy0: tx rings drained
[95626.450122] ieee80211 phy0: Command BASTREAM error 0x1
[95627.465449] ieee80211 phy0: Command BASTREAM error 0x1
[95628.475476] ieee80211 phy0: Command BASTREAM error 0x1
[95629.489810] ieee80211 phy0: Created a BA stream for 00:21:6a:49:37:e6 : tid 0
[95668.879720] ieee80211 phy0: Deleted BA stream index 0
[95668.879747] ieee80211 phy0: Remove stream for 00:21:6a:49:37:e6 0
[95670.831094] ieee80211 phy0: Added a new stream for 00:21:6a:49:37:e6 0

comment:30 in reply to: ↑ 29 Changed 11 months ago by lm@…

Replying to lm@…:

Same here. Installed kirkwood audi from snapshot from 2016.06.14. Wifi disconnects every couple of seconds:

I finally changed config to use different SSID for 11g and 11n networks. I also changed 11g channel and problem disappeared. There was another 11g network on channel and I think that was main reason for those disconnections.

comment:31 Changed 11 months ago by molocho

I have also faced this issue on an EA4500. I tried every OpenWrt trunk from the past 2 weeks, as well as the first releases to support this Router, the stable Chaos Calmer release and the Candyhouse mod. First i thought it is a problem with MTU PPPoE setting, so i tinkered with that and set MSS Clamping. None brought success. Trying to tamper with RTS/CTS / Threshold in wifi settings also brought no success. As for now, finding an unused WiFi channel seems to do it for now, but i am not convinced that this will do it from now on. My log looks the same than comment 9 starting time index 60000+. I strongly believe this is a driver issue.

comment:32 Changed 11 months ago by molocho

Testing for an hour confirms: using unused channels won't fix this for longer than a couple of minutes. Although all of the wireless traffic seems to work fine shortly after reboot, the connection gets horribly unstable after a few minutes uptime. On some links you'll wait 20sec until it starts loading, on other clicks you sometimes instantly get a "device not connected to internet" message. Interestingly, in my case it mainly affects four Apple iOS devices older than the iPhone 6s, which perfectly fits to the report made in comment #8. The 6s, and Intel wifi chipsets on a lenovo machine als well as an ath9k USB wifi Chip work flawless as clients, which might be the reason this problem never has been seen and adressed so far from whoever maintains the driver.

comment:33 Changed 11 months ago by lordgilman

I've been working with the author of the EA3500's wireless driver on the linux-wireless mailing list. You can see the latest message in our correspondence here:

http://marc.info/?l=linux-wireless&m=146752644907945

I've recompiled hostapd with full debugging support and captured the logs in that email for when the disconnects happen. No drop ever looks exactly the same but they all look like the WiFi device is unable to respond to the EAPOL message in time. This would explain why certain devices work fine on the same hardware while others are perpetually dropping connections, and why molocho's findings in comment 32 show that switching to a quiet channel doesn't help out here.

The timeouts for all of this stuff are hardcoded in hostapd, in src/ap/wpa_auth.c. I am tempted to get a patch to change these, but the fact that they're not configurable at runtime makes me a bit wary that there might be a good reason for those constants. I'd appreciate it if anyone from the OpenWRT project who's familiar with the workings of WPA could give some opinion here. If this patch isn't a bad idea it might be a good idea to ship the Audi Kirkwood binaries with a patched hostapd.

comment:34 Changed 11 months ago by lordgilman

Ok, I built wpad with increased timeouts. I also brought down the interval between GTK rekeys to make this easier to test. The rekey success rate was pretty good but there were still a few nasty drops. I managed to get this capture for one of them. The syslog with timestamps is first, the hostapd debug log is second:

Sun Jul 10 06:00:12 2016 daemon.debug hostapd: wlan1: WPA rekeying GTK
Sun Jul 10 06:00:12 2016 daemon.debug hostapd: wlan1: STA (bad phone) WPA: sending 1/2 msg of Group Key Handshake
Sun Jul 10 06:00:13 2016 daemon.debug hostapd: wlan1: STA (bad phone) WPA: EAPOL-Key timeout
Sun Jul 10 06:00:13 2016 daemon.debug hostapd: wlan1: STA (bad phone) WPA: sending 1/2 msg of Group Key Handshake
Sun Jul 10 06:00:15 2016 daemon.debug hostapd: wlan1: STA (bad phone) WPA: EAPOL-Key timeout
Sun Jul 10 06:00:15 2016 daemon.debug hostapd: wlan1: STA (bad phone) WPA: sending 1/2 msg of Group Key Handshake
Sun Jul 10 06:00:17 2016 daemon.debug hostapd: wlan1: STA (bad phone) WPA: EAPOL-Key timeout
Sun Jul 10 06:00:17 2016 daemon.debug hostapd: wlan1: STA (bad phone) WPA: sending 1/2 msg of Group Key Handshake
Sun Jul 10 06:00:19 2016 daemon.debug hostapd: wlan1: STA (bad phone) WPA: EAPOL-Key timeout
Sun Jul 10 06:00:19 2016 daemon.debug hostapd: wlan1: STA (bad phone) WPA: WPA_PTK: sm->Disconnect
Sun Jul 10 06:00:19 2016 daemon.debug hostapd: wlan1: STA (bad phone) WPA: event 3 notification
Sun Jul 10 06:00:19 2016 daemon.debug hostapd: wlan1: STA (bad phone) IEEE 802.1X: unauthorizing port
Sun Jul 10 06:00:19 2016 daemon.debug hostapd: wlan1: STA (bad phone) MLME: MLME-DEAUTHENTICATE.indication((bad phone), 2)
Sun Jul 10 06:00:19 2016 daemon.debug hostapd: wlan1: STA (bad phone) MLME: MLME-DELETEKEYS.request((bad phone))
Sun Jul 10 06:00:19 2016 kern.debug kernel: [110316.263312] ieee80211 phy1: Deleted BA stream index 0
Sun Jul 10 06:00:19 2016 kern.debug kernel: [110316.263422] ieee80211 phy1: Remove stream for (bad phone) 0
Sun Jul 10 06:00:24 2016 daemon.info hostapd: wlan1: STA (bad phone) IEEE 802.11: deauthenticated due to local deauth request

wlan1: WPA rekeying GTK
WPA: group state machine entering state SETKEYS (VLAN-ID 0)
GTK - hexdump(len=16): [REMOVED]
WPA: (bad phone) WPA_PTK_GROUP entering state REKEYNEGOTIATING
wlan1: STA (bad phone) WPA: sending 1/2 msg of Group Key Handshake
WPA: Send EAPOL(version=2 secure=1 mic=1 ack=1 install=0 pairwise=0 kde_len=24 keyidx=2 encr=1)
WPA: Replay Counter - hexdump(len=8): 00 00 00 00 00 00 00 10
Plaintext EAPOL-Key Key Data - hexdump(len=32): [REMOVED]
WPA: Use EAPOL-Key timeout of 1000 ms (retry counter 1)
wpa_group_setkeys: GKeyDoneStations=1
wlan1: STA (bad phone) WPA: EAPOL-Key timeout
WPA: (bad phone) WPA_PTK_GROUP entering state REKEYNEGOTIATING
wlan1: STA (bad phone) WPA: sending 1/2 msg of Group Key Handshake
WPA: Send EAPOL(version=2 secure=1 mic=1 ack=1 install=0 pairwise=0 kde_len=24 keyidx=2 encr=1)
WPA: Replay Counter - hexdump(len=8): 00 00 00 00 00 00 00 11
Plaintext EAPOL-Key Key Data - hexdump(len=32): [REMOVED]
WPA: Use EAPOL-Key timeout of 2000 ms (retry counter 2)
wlan1: STA (bad phone) WPA: EAPOL-Key timeout
WPA: (bad phone) WPA_PTK_GROUP entering state REKEYNEGOTIATING
wlan1: STA (bad phone) WPA: sending 1/2 msg of Group Key Handshake
WPA: Send EAPOL(version=2 secure=1 mic=1 ack=1 install=0 pairwise=0 kde_len=24 keyidx=2 encr=1)
WPA: Replay Counter - hexdump(len=8): 00 00 00 00 00 00 00 12
Plaintext EAPOL-Key Key Data - hexdump(len=32): [REMOVED]
WPA: Use EAPOL-Key timeout of 2000 ms (retry counter 3)
nl80211: BSS Event 59 (NL80211_CMD_FRAME) received for wlan1
nl80211: RX frame sa=cc:95:d7:d9:3d:95 freq=5180 ssi_signal=-67 fc=0x40 seq_ctrl=0x2c0 stype=4 (WLAN_FC_STYPE_PROBE_REQ) len=68
nl80211: BSS Event 59 (NL80211_CMD_FRAME) received for wlan1
nl80211: RX frame sa=cc:95:d7:d9:3d:95 freq=5180 ssi_signal=-67 fc=0x40 seq_ctrl=0x2d0 stype=4 (WLAN_FC_STYPE_PROBE_REQ) len=175
nl80211: BSS Event 59 (NL80211_CMD_FRAME) received for wlan1
nl80211: RX frame sa=cc:95:d7:d9:3d:95 freq=5180 ssi_signal=-68 fc=0x40 seq_ctrl=0x2e0 stype=4 (WLAN_FC_STYPE_PROBE_REQ) len=42
nl80211: send_mlme - da= cc:95:d7:d9:3d:95 noack=1 freq=0 no_cck=0 offchanok=0 wait_time=0 fc=0x50 (WLAN_FC_STYPE_PROBE_RESP) nlmode=3
nl80211: send_mlme -> send_frame
nl80211: send_frame - Use bss->freq=5180
nl80211: send_frame -> send_frame_cmd
nl80211: Drop oldest pending send action cookie 0x0
nl80211: BSS Event 59 (NL80211_CMD_FRAME) received for wlan1
nl80211: RX frame sa=cc:95:d7:d9:3d:95 freq=5180 ssi_signal=-67 fc=0x40 seq_ctrl=0x2f0 stype=4 (WLAN_FC_STYPE_PROBE_REQ) len=149
nl80211: send_mlme - da= cc:95:d7:d9:3d:95 noack=1 freq=0 no_cck=0 offchanok=0 wait_time=0 fc=0x50 (WLAN_FC_STYPE_PROBE_RESP) nlmode=3
nl80211: send_mlme -> send_frame
nl80211: send_frame - Use bss->freq=5180
nl80211: send_frame -> send_frame_cmd
nl80211: Drop oldest pending send action cookie 0x0
wlan1: STA (bad phone) WPA: EAPOL-Key timeout
WPA: (bad phone) WPA_PTK_GROUP entering state REKEYNEGOTIATING
wlan1: STA (bad phone) WPA: sending 1/2 msg of Group Key Handshake
WPA: Send EAPOL(version=2 secure=1 mic=1 ack=1 install=0 pairwise=0 kde_len=24 keyidx=2 encr=1)
WPA: Replay Counter - hexdump(len=8): 00 00 00 00 00 00 00 13
Plaintext EAPOL-Key Key Data - hexdump(len=32): [REMOVED]
WPA: Use EAPOL-Key timeout of 2000 ms (retry counter 4)
wlan1: STA (bad phone) WPA: EAPOL-Key timeout
WPA: (bad phone) WPA_PTK_GROUP entering state REKEYNEGOTIATING
WPA: (bad phone) WPA_PTK_GROUP entering state KEYERROR
WPA: group state machine entering state SETKEYSDONE (VLAN-ID 0)
wpa_driver_nl80211_set_key: ifindex=16 (wlan1) alg=3 addr=0x88608 key_idx=2 set_tx=1 seq_len=0 key_len=16
nl80211: KEY_DATA - hexdump(len=16): [REMOVED]
   broadcast key
wlan1: STA (bad phone) WPA: WPA_PTK: sm->Disconnect
WPA: (bad phone) WPA_PTK entering state DISCONNECT
wpa_sta_disconnect STA (bad phone)
hostapd_wpa_auth_disconnect: WPA authenticator requests disconnect: STA (bad phone) reason 2
wlan1: ap_sta_disconnect addr (bad phone) reason=2
nl80211: send_mlme - da= (bad phone) noack=0 freq=0 no_cck=0 offchanok=0 wait_time=0 fc=0xc0 (WLAN_FC_STYPE_DEAUTH) nlmode=3
nl80211: send_mlme -> send_frame
nl80211: send_frame - Use bss->freq=5180
nl80211: send_frame -> send_frame_cmd
nl80211: Drop oldest pending send action cookie 0x0
wlan1: AP-STA-DISCONNECTED (bad phone)
wlan1: STA (bad phone) WPA: event 3 notification
wpa_driver_nl80211_set_key: ifindex=16 (wlan1) alg=0 addr=0xb6eda428 key_idx=0 set_tx=1 seq_len=0 key_len=0
   addr=(bad phone)
wlan1: ap_sta_disconnect: reschedule ap_handle_timer timeout for (bad phone) (5 seconds - AP_MAX_INACTIVITY_AFTER_DEAUTH)
WPA: (bad phone) WPA_PTK_GROUP entering state IDLE
WPA: (bad phone) WPA_PTK entering state DISCONNECTED
WPA: (bad phone) WPA_PTK entering state INITIALIZE
wpa_driver_nl80211_set_key: ifindex=16 (wlan1) alg=0 addr=0xb6eda428 key_idx=0 set_tx=1 seq_len=0 key_len=0
   addr=(bad phone)
nl80211: Set STA flags - ifname=wlan1 addr=(bad phone) total_flags=0x2 flags_or=0x0 flags_and=0xfffffffe authorized=0
wlan1: STA (bad phone) IEEE 802.1X: unauthorizing port
nl80211: Drv Event 60 (NL80211_CMD_FRAME_TX_STATUS) received for wlan1
nl80211: Frame TX status event
wlan1: Event TX_STATUS (17) received
mgmt::deauth cb
STA (bad phone) acknowledged deauth
wlan1: Deauthentication callback for STA (bad phone)
wlan1: Removing STA (bad phone) from kernel driver
nl80211: sta_remove -> DEL_STATION wlan1 (bad phone) --> 0 (No error information)
wlan1: STA (bad phone) MLME: MLME-DEAUTHENTICATE.indication((bad phone), 2)
wlan1: STA (bad phone) MLME: MLME-DELETEKEYS.request((bad phone))
wpa_driver_nl80211_set_key: ifindex=16 (wlan1) alg=0 addr=0xb6eda428 key_idx=0 set_tx=1 seq_len=0 key_len=0
   addr=(bad phone)
wlan1: Event EAPOL_TX_STATUS (38) received
Ignore TX status for Data frame to STA (bad phone) that is not currently associated
nl80211: Drv Event 20 (NL80211_CMD_DEL_STATION) received for wlan1
nl80211: Delete station (bad phone)
nl80211: BSS Event 59 (NL80211_CMD_FRAME) received for wlan1
nl80211: RX frame sa=(bad phone) freq=5180 ssi_signal=-44 fc=0x40 seq_ctrl=0x71e0 stype=4 (WLAN_FC_STYPE_PROBE_REQ) len=120
nl80211: send_mlme - da= (bad phone) noack=0 freq=0 no_cck=0 offchanok=0 wait_time=0 fc=0x50 (WLAN_FC_STYPE_PROBE_RESP) nlmode=3
nl80211: send_mlme -> send_frame
nl80211: send_frame - Use bss->freq=5180
nl80211: send_frame -> send_frame_cmd
nl80211: Drop oldest pending send action cookie 0x0
wlan1: Event EAPOL_TX_STATUS (38) received
Ignore TX status for Data frame to STA (bad phone) that is not currently associated
nl80211: Drv Event 60 (NL80211_CMD_FRAME_TX_STATUS) received for wlan1
nl80211: Frame TX status event
wlan1: Event TX_STATUS (17) received
wlan1: Event EAPOL_TX_STATUS (38) received
Ignore TX status for Data frame to STA (bad phone) that is not currently associated
wlan1: Event EAPOL_TX_STATUS (38) received
Ignore TX status for Data frame to STA (bad phone) that is not currently associated
nl80211: BSS Event 59 (NL80211_CMD_FRAME) received for wlan1
nl80211: RX frame sa=(bad phone) freq=5180 ssi_signal=-43 fc=0x40 seq_ctrl=0x7350 stype=4 (WLAN_FC_STYPE_PROBE_REQ) len=106
nl80211: send_mlme - da= (bad phone) noack=1 freq=0 no_cck=0 offchanok=0 wait_time=0 fc=0x50 (WLAN_FC_STYPE_PROBE_RESP) nlmode=3
nl80211: send_mlme -> send_frame
nl80211: send_frame - Use bss->freq=5180
nl80211: send_frame -> send_frame_cmd
nl80211: Drop oldest pending send action cookie 0x0
nl80211: BSS Event 59 (NL80211_CMD_FRAME) received for wlan1
nl80211: RX frame sa=(bad phone) freq=5180 ssi_signal=-43 fc=0x40 seq_ctrl=0x7360 stype=4 (WLAN_FC_STYPE_PROBE_REQ) len=106
nl80211: send_mlme - da= (bad phone) noack=1 freq=0 no_cck=0 offchanok=0 wait_time=0 fc=0x50 (WLAN_FC_STYPE_PROBE_RESP) nlmode=3
nl80211: send_mlme -> send_frame
nl80211: send_frame - Use bss->freq=5180
nl80211: send_frame -> send_frame_cmd
nl80211: Drop oldest pending send action cookie 0x0
nl80211: BSS Event 59 (NL80211_CMD_FRAME) received for wlan1
nl80211: RX frame sa=e0:66:78:80:e1:4a freq=5180 ssi_signal=-74 fc=0x40 seq_ctrl=0xc0 stype=4 (WLAN_FC_STYPE_PROBE_REQ) len=131
nl80211: send_mlme - da= e0:66:78:80:e1:4a noack=1 freq=0 no_cck=0 offchanok=0 wait_time=0 fc=0x50 (WLAN_FC_STYPE_PROBE_RESP) nlmode=3
nl80211: send_mlme -> send_frame
nl80211: send_frame - Use bss->freq=5180
nl80211: send_frame -> send_frame_cmd
nl80211: Drop oldest pending send action cookie 0x0
wlan1: ap_handle_timer: (bad phone) flags=0x8a00 timeout_next=3
wlan1: STA (bad phone) IEEE 802.11: deauthenticated due to local deauth request
nl80211: sta_remove -> DEL_STATION wlan1 (bad phone) --> -2 (No such file or directory)
hostapd_ht_operation_update current operation mode=0x4
hostapd_ht_operation_update new operation mode=0x0 changes=1
nl80211: Set beacon (beacon_set=1)
nl80211: Beacon head - hexdump(len=65): 80 00 00 00 ff ff ff ff ff ff 94 10 3e 8f d2 db 94 10 3e 8f d2 db 00 00 00 00 00 00 00 00 00 00 64 00 31 00 00 0e 67 69 6c 6d 61 6e 20 6f 70 65 6e 77 72 74 01 08 8c 12 98 24 b0 48 60 6c 03 01 24
nl80211: Beacon tail - hexdump(len=118): 07 06 30 30 20 24 04 14 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 02 0c 00 2d 1a ec 0b 03 ff ff ff 00 01 00 00 00 00 00 00 00 01 00 00 00 00 00 00 00 00 00 00 3d 16 24 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 7f 08 00 00 00 00 00 00 00 40 dd 18 00 50 f2 02 01 01 00 00 03 a4 00 00 27 a4 00 00 42 43 5e 00 62 32 2f 00
nl80211: ifindex=16
nl80211: beacon_int=100
nl80211: dtim_period=2
nl80211: ssid - hexdump_ascii(len=14):
     67 69 6c 6d 61 6e 20 6f 70 65 6e 77 72 74         gilman openwrt
  * beacon_int=100
nl80211: hidden SSID not in use
nl80211: privacy=1
nl80211: auth_algs=0x1
nl80211: wpa_version=0x2
nl80211: key_mgmt_suites=0x2
nl80211: pairwise_ciphers=0x10
nl80211: group_cipher=0x10
nl80211: SMPS mode - off
nl80211: beacon_ies - hexdump(len=10): 7f 08 00 00 00 00 00 00 00 40
nl80211: proberesp_ies - hexdump(len=10): 7f 08 00 00 00 00 00 00 00 40
nl80211: assocresp_ies - hexdump(len=10): 7f 08 00 00 00 00 00 00 00 40
ap_free_sta: cancel ap_handle_timer for (bad phone)
nl80211: BSS Event 59 (NL80211_CMD_FRAME) received for wlan1
nl80211: RX frame sa=cc:95:d7:d9:3d:95 freq=5180 ssi_signal=-67 fc=0x40 seq_ctrl=0x2c0 stype=4 (WLAN_FC_STYPE_PROBE_REQ) len=68
nl80211: BSS Event 59 (NL80211_CMD_FRAME) received for wlan1
nl80211: RX frame sa=cc:95:d7:d9:3d:95 freq=5180 ssi_signal=-68 fc=0x40 seq_ctrl=0x2d0 stype=4 (WLAN_FC_STYPE_PROBE_REQ) len=175
nl80211: BSS Event 59 (NL80211_CMD_FRAME) received for wlan1
nl80211: RX frame sa=cc:95:d7:d9:3d:95 freq=5180 ssi_signal=-68 fc=0x40 seq_ctrl=0x2e0 stype=4 (WLAN_FC_STYPE_PROBE_REQ) len=42
nl80211: send_mlme - da= cc:95:d7:d9:3d:95 noack=1 freq=0 no_cck=0 offchanok=0 wait_time=0 fc=0x50 (WLAN_FC_STYPE_PROBE_RESP) nlmode=3
nl80211: send_mlme -> send_frame
nl80211: send_frame - Use bss->freq=5180
nl80211: send_frame -> send_frame_cmd
nl80211: Drop oldest pending send action cookie 0x0
nl80211: BSS Event 59 (NL80211_CMD_FRAME) received for wlan1
nl80211: RX frame sa=cc:95:d7:d9:3d:95 freq=5180 ssi_signal=-68 fc=0x40 seq_ctrl=0x2f0 stype=4 (WLAN_FC_STYPE_PROBE_REQ) len=149
nl80211: send_mlme - da= cc:95:d7:d9:3d:95 noack=1 freq=0 no_cck=0 offchanok=0 wait_time=0 fc=0x50 (WLAN_FC_STYPE_PROBE_RESP) nlmode=3
nl80211: send_mlme -> send_frame
nl80211: send_frame - Use bss->freq=5180
nl80211: send_frame -> send_frame_cmd
nl80211: Drop oldest pending send action cookie 0x0
wlan1: WPA rekeying GTK
WPA: group state machine entering state SETKEYS (VLAN-ID 0)
GTK - hexdump(len=16): [REMOVED]
wpa_group_setkeys: GKeyDoneStations=0
WPA: group state machine entering state SETKEYSDONE (VLAN-ID 0)
wpa_driver_nl80211_set_key: ifindex=16 (wlan1) alg=3 addr=0x88608 key_idx=1 set_tx=1 seq_len=0 key_len=16
nl80211: KEY_DATA - hexdump(len=16): [REMOVED]
   broadcast key
nl80211: BSS Event 59 (NL80211_CMD_FRAME) received for wlan1
nl80211: RX frame sa=(bad phone) freq=5180 ssi_signal=-62 fc=0x40 seq_ctrl=0x7730 stype=4 (WLAN_FC_STYPE_PROBE_REQ) len=106
nl80211: send_mlme - da= (bad phone) noack=1 freq=0 no_cck=0 offchanok=0 wait_time=0 fc=0x50 (WLAN_FC_STYPE_PROBE_RESP) nlmode=3
nl80211: send_mlme -> send_frame
nl80211: send_frame - Use bss->freq=5180
nl80211: send_frame -> send_frame_cmd
nl80211: Drop oldest pending send action cookie 0x0
nl80211: BSS Event 59 (NL80211_CMD_FRAME) received for wlan1
nl80211: RX frame sa=(bad phone) freq=5180 ssi_signal=-62 fc=0x40 seq_ctrl=0x7740 stype=4 (WLAN_FC_STYPE_PROBE_REQ) len=106
nl80211: send_mlme - da= (bad phone) noack=1 freq=0 no_cck=0 offchanok=0 wait_time=0 fc=0x50 (WLAN_FC_STYPE_PROBE_RESP) nlmode=3
nl80211: send_mlme -> send_frame
nl80211: send_frame - Use bss->freq=5180
nl80211: send_frame -> send_frame_cmd
nl80211: Drop oldest pending send action cookie 0x0
nl80211: BSS Event 59 (NL80211_CMD_FRAME) received for wlan1
nl80211: RX frame sa=cc:95:d7:d9:3d:95 freq=5180 ssi_signal=-67 fc=0x40 seq_ctrl=0x2c0 stype=4 (WLAN_FC_STYPE_PROBE_REQ) len=68
nl80211: BSS Event 59 (NL80211_CMD_FRAME) received for wlan1
nl80211: RX frame sa=cc:95:d7:d9:3d:95 freq=5180 ssi_signal=-68 fc=0x40 seq_ctrl=0x2d0 stype=4 (WLAN_FC_STYPE_PROBE_REQ) len=175
nl80211: BSS Event 59 (NL80211_CMD_FRAME) received for wlan1
nl80211: RX frame sa=cc:95:d7:d9:3d:95 freq=5180 ssi_signal=-68 fc=0x40 seq_ctrl=0x2e0 stype=4 (WLAN_FC_STYPE_PROBE_REQ) len=42
nl80211: send_mlme - da= cc:95:d7:d9:3d:95 noack=1 freq=0 no_cck=0 offchanok=0 wait_time=0 fc=0x50 (WLAN_FC_STYPE_PROBE_RESP) nlmode=3
nl80211: send_mlme -> send_frame
nl80211: send_frame - Use bss->freq=5180
nl80211: send_frame -> send_frame_cmd
nl80211: Drop oldest pending send action cookie 0x0
nl80211: BSS Event 59 (NL80211_CMD_FRAME) received for wlan1
nl80211: RX frame sa=cc:95:d7:d9:3d:95 freq=5180 ssi_signal=-67 fc=0x40 seq_ctrl=0x2f0 stype=4 (WLAN_FC_STYPE_PROBE_REQ) len=149
nl80211: send_mlme - da= cc:95:d7:d9:3d:95 noack=1 freq=0 no_cck=0 offchanok=0 wait_time=0 fc=0x50 (WLAN_FC_STYPE_PROBE_RESP) nlmode=3
nl80211: send_mlme -> send_frame
nl80211: send_frame - Use bss->freq=5180
nl80211: send_frame -> send_frame_cmd
nl80211: Drop oldest pending send action cookie 0x0

Do you see the four "Event EAPOL_TX_STATUS (38) received" lines that come in after the sm->Disconnect log line? I am wondering if that's the four EAPOL responses coming in super late - in this case 7 or 8 seconds after they were initially sent! I'm going to try rebuilding with eapol_key_timeout_subseq set to 10 seconds and everything else left on default.

comment:35 Changed 11 months ago by anonymous

thanks for following up on this, lordgilman. I've been seeing the same thing on my EA4500, DD trunk, using 2013 MacBook Pro and iPhone 6s as clients ("tx ring drained", "Command BASTREAM error 0x1", etc.). I tried disabling encryption but still got the dropouts.

comment:36 Changed 11 months ago by molocho

yea, thanks for your work on this, lordgilman. All i can offer at this time is to do some excessive testing. And #35 is right, the 6S also has the problem.

comment:37 Changed 11 months ago by anonymous

I have the same issue with my EA3500 and my Samsung Galaxy S6 phone.
I tried to sniff wifi communication between my phone and the router and tried to log hostapd messages and got the same result as above (EAPOL-Key timeout).

When the router says it is sending "1/2 msg of Group Key Handshake" there's no communication between the router and the phone.

### syslog ###
2016-07-13T15:10:00+02:00 CiscoJH hostapd: wlan1: WPA rekeying GTK
2016-07-13T15:10:00+02:00 CiscoJH hostapd: wlan1: STA <Samsung_S6> WPA: sending 1/2 msg of Group Key Handshake
2016-07-13T15:10:01+02:00 CiscoJH hostapd: wlan1: STA <Samsung_S6> WPA: EAPOL-Key timeout
2016-07-13T15:10:01+02:00 CiscoJH hostapd: wlan1: STA <Samsung_S6> WPA: sending 1/2 msg of Group Key Handshake
2016-07-13T15:10:02+02:00 CiscoJH hostapd: wlan1: STA <Samsung_S6> WPA: EAPOL-Key timeout
2016-07-13T15:10:02+02:00 CiscoJH hostapd: wlan1: STA <Samsung_S6> WPA: sending 1/2 msg of Group Key Handshake
2016-07-13T15:10:03+02:00 CiscoJH hostapd: wlan1: STA <Samsung_S6> WPA: EAPOL-Key timeout
2016-07-13T15:10:03+02:00 CiscoJH hostapd: wlan1: STA <Samsung_S6> WPA: sending 1/2 msg of Group Key Handshake
2016-07-13T15:10:04+02:00 CiscoJH hostapd: wlan1: STA <Samsung_S6> WPA: EAPOL-Key timeout
2016-07-13T15:10:04+02:00 CiscoJH hostapd: wlan1: STA <Samsung_S6> WPA: WPA_PTK: sm->Disconnect
2016-07-13T15:10:04+02:00 CiscoJH hostapd: wlan1: STA <Samsung_S6> WPA: event 3 notification
2016-07-13T15:10:04+02:00 CiscoJH hostapd: wlan1: STA <Samsung_S6> IEEE 802.1X: unauthorizing port
2016-07-13T15:10:06+02:00 CiscoJH hostapd: wlan1: STA <Samsung_S6> MLME: MLME-DEAUTHENTICATE.indication(<Samsung_S6>, 2)
2016-07-13T15:10:06+02:00 CiscoJH hostapd: wlan1: STA <Samsung_S6> MLME: MLME-DELETEKEYS.request(<Samsung_S6>)
2016-07-13T15:10:09+02:00 CiscoJH hostapd: wlan1: STA <Samsung_S6> IEEE 802.11: deauthenticated due to local deauth request
2016-07-13T15:10:15+02:00 CiscoJH hostapd: wlan1: STA <Samsung_S6> IEEE 802.11: authentication OK (open system)
2016-07-13T15:10:15+02:00 CiscoJH hostapd: wlan1: STA <Samsung_S6> MLME: MLME-AUTHENTICATE.indication(<Samsung_S6>, OPEN_SYSTEM)
2016-07-13T15:10:15+02:00 CiscoJH hostapd: wlan1: STA <Samsung_S6> MLME: MLME-DELETEKEYS.request(<Samsung_S6>)
2016-07-13T15:10:15+02:00 CiscoJH hostapd: wlan1: STA <Samsung_S6> IEEE 802.11: authenticated
2016-07-13T15:10:15+02:00 CiscoJH hostapd: wlan1: STA <Samsung_S6> IEEE 802.11: association OK (aid 1)
2016-07-13T15:10:15+02:00 CiscoJH hostapd: wlan1: STA <Samsung_S6> IEEE 802.11: associated (aid 1)
2016-07-13T15:10:15+02:00 CiscoJH hostapd: wlan1: STA <Samsung_S6> MLME: MLME-ASSOCIATE.indication(<Samsung_S6>)
2016-07-13T15:10:15+02:00 CiscoJH hostapd: wlan1: STA <Samsung_S6> MLME: MLME-DELETEKEYS.request(<Samsung_S6>)
2016-07-13T15:10:15+02:00 CiscoJH hostapd: wlan1: STA <Samsung_S6> IEEE 802.11: binding station to interface 'wlan1'
2016-07-13T15:10:15+02:00 CiscoJH hostapd: wlan1: STA <Samsung_S6> WPA: event 1 notification
2016-07-13T15:10:15+02:00 CiscoJH hostapd: wlan1: STA <Samsung_S6> WPA: start authentication
2016-07-13T15:10:15+02:00 CiscoJH hostapd: wlan1: STA <Samsung_S6> IEEE 802.1X: unauthorizing port
2016-07-13T15:10:15+02:00 CiscoJH hostapd: wlan1: STA <Samsung_S6> WPA: sending 1/4 msg of 4-Way Handshake
2016-07-13T15:10:15+02:00 CiscoJH hostapd: wlan1: STA <Samsung_S6> WPA: received EAPOL-Key frame (2/4 Pairwise)
2016-07-13T15:10:15+02:00 CiscoJH hostapd: wlan1: STA <Samsung_S6> WPA: sending 3/4 msg of 4-Way Handshake
2016-07-13T15:10:15+02:00 CiscoJH hostapd: wlan1: STA <Samsung_S6> WPA: received EAPOL-Key frame (4/4 Pairwise)

### wifi packets ###
No.     Time           Time               Source                Destination           Protocol Length Info
  29686 1694.128595    15:10:00.085926    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1408, FN=0, Flags=........C, BI=100, SSID=JH5
  29687 1694.231113    15:10:00.188444    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1409, FN=0, Flags=........C, BI=100, SSID=JH5
  29688 1694.333516    15:10:00.290847    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1410, FN=0, Flags=........C, BI=100, SSID=JH5
  29689 1694.435974    15:10:00.393305    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1411, FN=0, Flags=........C, BI=100, SSID=JH5
  29690 1694.538401    15:10:00.495732    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1412, FN=0, Flags=........C, BI=100, SSID=JH5
  29691 1694.640792    15:10:00.598123    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1413, FN=0, Flags=........C, BI=100, SSID=JH5
  29692 1694.743188    15:10:00.700519    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1414, FN=0, Flags=........C, BI=100, SSID=JH5
  29693 1694.845583    15:10:00.802914    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1415, FN=0, Flags=........C, BI=100, SSID=JH5
  29694 1694.947988    15:10:00.905319    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1416, FN=0, Flags=........C, BI=100, SSID=JH5
  29695 1695.050327    15:10:01.007658    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1417, FN=0, Flags=........C, BI=100, SSID=JH5
  29696 1695.152794    15:10:01.110125    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1418, FN=0, Flags=........C, BI=100, SSID=JH5
  29697 1695.255173    15:10:01.212504    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1419, FN=0, Flags=........C, BI=100, SSID=JH5
  29698 1695.357567    15:10:01.314898    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1420, FN=0, Flags=........C, BI=100, SSID=JH5
  29699 1695.459944    15:10:01.417275    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1421, FN=0, Flags=........C, BI=100, SSID=JH5
  29700 1695.562359    15:10:01.519690    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1422, FN=0, Flags=........C, BI=100, SSID=JH5
  29701 1695.664697    15:10:01.622028    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1423, FN=0, Flags=........C, BI=100, SSID=JH5
  29702 1695.767157    15:10:01.724488    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1424, FN=0, Flags=........C, BI=100, SSID=JH5
  29703 1695.869551    15:10:01.826882    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1425, FN=0, Flags=........C, BI=100, SSID=JH5
  29704 1695.971955    15:10:01.929286    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1426, FN=0, Flags=........C, BI=100, SSID=JH5
  29705 1696.074348    15:10:02.031679    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1427, FN=0, Flags=........C, BI=100, SSID=JH5
  29706 1696.176743    15:10:02.134074    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1428, FN=0, Flags=........C, BI=100, SSID=JH5
  29707 1696.279145    15:10:02.236476    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1429, FN=0, Flags=........C, BI=100, SSID=JH5
  29708 1696.381627    15:10:02.338958    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1430, FN=0, Flags=........C, BI=100, SSID=JH5
  29709 1696.484023    15:10:02.441354    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1431, FN=0, Flags=........C, BI=100, SSID=JH5
  29710 1696.586411    15:10:02.543742    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1432, FN=0, Flags=........C, BI=100, SSID=JH5
  29711 1696.688817    15:10:02.646148    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1433, FN=0, Flags=........C, BI=100, SSID=JH5
  29712 1696.791210    15:10:02.748541    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1434, FN=0, Flags=........C, BI=100, SSID=JH5
  29713 1696.893613    15:10:02.850944    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1435, FN=0, Flags=........C, BI=100, SSID=JH5
  29714 1696.995898    15:10:02.953229    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1436, FN=0, Flags=........C, BI=100, SSID=JH5
  29715 1697.098395    15:10:03.055726    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1437, FN=0, Flags=........C, BI=100, SSID=JH5
  29716 1697.200786    15:10:03.158117    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1438, FN=0, Flags=........C, BI=100, SSID=JH5
  29717 1697.303186    15:10:03.260517    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1439, FN=0, Flags=........C, BI=100, SSID=JH5
  29718 1697.405590    15:10:03.362921    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1440, FN=0, Flags=........C, BI=100, SSID=JH5
  29719 1697.507993    15:10:03.465324    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1441, FN=0, Flags=........C, BI=100, SSID=JH5
  29720 1697.610411    15:10:03.567742    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1442, FN=0, Flags=........C, BI=100, SSID=JH5
  29721 1697.712661    15:10:03.669992    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1443, FN=0, Flags=........C, BI=100, SSID=JH5
  29722 1697.815177    15:10:03.772508    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1444, FN=0, Flags=........C, BI=100, SSID=JH5
  29723 1697.917579    15:10:03.874910    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1445, FN=0, Flags=........C, BI=100, SSID=JH5
  29724 1698.019959    15:10:03.977290    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1446, FN=0, Flags=........C, BI=100, SSID=JH5
  29725 1698.122366    15:10:04.079697    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1447, FN=0, Flags=........C, BI=100, SSID=JH5
  29726 1698.224763    15:10:04.182094    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1448, FN=0, Flags=........C, BI=100, SSID=JH5
  29727 1698.327213    15:10:04.284544    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1449, FN=0, Flags=........C, BI=100, SSID=JH5
  29728 1698.429640    15:10:04.386971    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1450, FN=0, Flags=........C, BI=100, SSID=JH5
  29729 1698.532039    15:10:04.489370    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1451, FN=0, Flags=........C, BI=100, SSID=JH5
  29730 1698.634441    15:10:04.591772    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1452, FN=0, Flags=........C, BI=100, SSID=JH5
  29731 1698.736831    15:10:04.694162    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1453, FN=0, Flags=........C, BI=100, SSID=JH5
  29732 1698.839229    15:10:04.796560    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1454, FN=0, Flags=........C, BI=100, SSID=JH5
  29733 1698.941632    15:10:04.898963    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1455, FN=0, Flags=........C, BI=100, SSID=JH5
  29734 1699.044042    15:10:05.001373    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1456, FN=0, Flags=........C, BI=100, SSID=JH5
  29735 1699.146424    15:10:05.103755    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1457, FN=0, Flags=........C, BI=100, SSID=JH5
  29736 1699.248820    15:10:05.206151    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1458, FN=0, Flags=........C, BI=100, SSID=JH5
  29737 1699.351218    15:10:05.308549    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1459, FN=0, Flags=........C, BI=100, SSID=JH5
  29738 1699.453599    15:10:05.410930    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1460, FN=0, Flags=........C, BI=100, SSID=JH5
  29739 1699.556013    15:10:05.513344    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1461, FN=0, Flags=........C, BI=100, SSID=JH5
  29740 1699.658407    15:10:05.615738    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1462, FN=0, Flags=........C, BI=100, SSID=JH5
  29741 1699.760690    15:10:05.718021    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1463, FN=0, Flags=........C, BI=100, SSID=JH5
  29742 1699.863173    15:10:05.820504    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1464, FN=0, Flags=........C, BI=100, SSID=JH5
  29743 1699.965605    15:10:05.922936    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1465, FN=0, Flags=........C, BI=100, SSID=JH5
  29744 1700.068000    15:10:06.025331    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1466, FN=0, Flags=........C, BI=100, SSID=JH5
  29745 1700.170401    15:10:06.127732    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1467, FN=0, Flags=........C, BI=100, SSID=JH5
  29746 1700.272793    15:10:06.230124    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1468, FN=0, Flags=........C, BI=100, SSID=JH5
  29747 1700.375269    15:10:06.332600    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1469, FN=0, Flags=........C, BI=100, SSID=JH5
  29748 1700.477539    15:10:06.434870    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1470, FN=0, Flags=........C, BI=100, SSID=JH5
  29749 1700.580035    15:10:06.537366    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1471, FN=0, Flags=........C, BI=100, SSID=JH5
  29750 1700.682465    15:10:06.639796    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1472, FN=0, Flags=........C, BI=100, SSID=JH5
  29751 1700.784855    15:10:06.742186    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1473, FN=0, Flags=........C, BI=100, SSID=JH5
  29752 1700.887255    15:10:06.844586    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1474, FN=0, Flags=........C, BI=100, SSID=JH5
  29753 1700.989653    15:10:06.946984    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1475, FN=0, Flags=........C, BI=100, SSID=JH5
  29754 1701.092049    15:10:07.049380    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1476, FN=0, Flags=........C, BI=100, SSID=JH5
  29755 1701.194440    15:10:07.151771    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1477, FN=0, Flags=........C, BI=100, SSID=JH5
  29756 1701.296718    15:10:07.254049    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1478, FN=0, Flags=........C, BI=100, SSID=JH5
  29757 1701.399249    15:10:07.356580    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1479, FN=0, Flags=........C, BI=100, SSID=JH5
  29758 1701.501636    15:10:07.458967    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1480, FN=0, Flags=........C, BI=100, SSID=JH5
  29759 1701.604029    15:10:07.561360    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1481, FN=0, Flags=........C, BI=100, SSID=JH5
  29760 1701.706431    15:10:07.663762    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1482, FN=0, Flags=........C, BI=100, SSID=JH5
  29761 1701.808823    15:10:07.766154    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1483, FN=0, Flags=........C, BI=100, SSID=JH5
  29762 1701.911227    15:10:07.868558    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1484, FN=0, Flags=........C, BI=100, SSID=JH5
  29763 1702.013591    15:10:07.970922    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1485, FN=0, Flags=........C, BI=100, SSID=JH5
  29764 1702.116021    15:10:08.073352    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1486, FN=0, Flags=........C, BI=100, SSID=JH5
  29765 1702.218414    15:10:08.175745    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1487, FN=0, Flags=........C, BI=100, SSID=JH5
  29766 1702.320893    15:10:08.278224    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1488, FN=0, Flags=........C, BI=100, SSID=JH5
  29767 1702.423294    15:10:08.380625    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1489, FN=0, Flags=........C, BI=100, SSID=JH5
  29768 1702.525688    15:10:08.483019    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1490, FN=0, Flags=........C, BI=100, SSID=JH5
  29769 1702.627969    15:10:08.585300    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1491, FN=0, Flags=........C, BI=100, SSID=JH5
  29770 1702.730483    15:10:08.687814    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1492, FN=0, Flags=........C, BI=100, SSID=JH5
  29771 1702.832864    15:10:08.790195    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1493, FN=0, Flags=........C, BI=100, SSID=JH5
  29772 1702.935275    15:10:08.892606    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1494, FN=0, Flags=........C, BI=100, SSID=JH5
  29773 1703.037673    15:10:08.995004    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1495, FN=0, Flags=........C, BI=100, SSID=JH5
  29774 1703.140071    15:10:09.097402    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1496, FN=0, Flags=........C, BI=100, SSID=JH5
  29775 1703.242465    15:10:09.199796    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1497, FN=0, Flags=........C, BI=100, SSID=JH5
  29776 1703.344828    15:10:09.302159    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1498, FN=0, Flags=........C, BI=100, SSID=JH5
  29777 1703.447261    15:10:09.404592    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1499, FN=0, Flags=........C, BI=100, SSID=JH5
  29778 1703.549650    15:10:09.506981    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1500, FN=0, Flags=........C, BI=100, SSID=JH5
  29779 1703.652053    15:10:09.609384    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1501, FN=0, Flags=........C, BI=100, SSID=JH5
  29780 1703.754453    15:10:09.711784    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1502, FN=0, Flags=........C, BI=100, SSID=JH5
  29781 1703.856856    15:10:09.814187    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1503, FN=0, Flags=........C, BI=100, SSID=JH5
  29782 1703.959244    15:10:09.916575    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1504, FN=0, Flags=........C, BI=100, SSID=JH5
  29783 1704.061605    15:10:10.018936    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1505, FN=0, Flags=........C, BI=100, SSID=JH5
  29784 1704.164046    15:10:10.121377    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1506, FN=0, Flags=........C, BI=100, SSID=JH5
  29785 1704.266514    15:10:10.223845    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1507, FN=0, Flags=........C, BI=100, SSID=JH5
  29786 1704.368920    15:10:10.326251    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1508, FN=0, Flags=........C, BI=100, SSID=JH5
  29787 1704.471313    15:10:10.428644    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1509, FN=0, Flags=........C, BI=100, SSID=JH5
  29788 1704.573716    15:10:10.531047    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1510, FN=0, Flags=........C, BI=100, SSID=JH5
  29789 1704.676111    15:10:10.633442    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1511, FN=0, Flags=........C, BI=100, SSID=JH5
  29790 1704.778495    15:10:10.735826    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1512, FN=0, Flags=........C, BI=100, SSID=JH5
  29791 1704.880891    15:10:10.838222    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1513, FN=0, Flags=........C, BI=100, SSID=JH5
  29792 1704.983285    15:10:10.940616    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1514, FN=0, Flags=........C, BI=100, SSID=JH5
  29793 1705.085695    15:10:11.043026    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1515, FN=0, Flags=........C, BI=100, SSID=JH5
  29794 1705.188096    15:10:11.145427    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1516, FN=0, Flags=........C, BI=100, SSID=JH5
  29795 1705.290502    15:10:11.247833    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1517, FN=0, Flags=........C, BI=100, SSID=JH5
  29796 1705.392891    15:10:11.350222    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1518, FN=0, Flags=........C, BI=100, SSID=JH5
  29797 1705.495292    15:10:11.452623    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1519, FN=0, Flags=........C, BI=100, SSID=JH5
  29798 1705.597683    15:10:11.555014    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1520, FN=0, Flags=........C, BI=100, SSID=JH5
  29799 1705.601268    15:10:11.558599    SamsungE_2e:4e:b7     Cisco-Li_72:35:d9     802.11   53     Null function (No data), SN=698, FN=0, Flags=...PR..TC
  29800 1705.601376    15:10:11.558707                          SamsungE_2e:4e:b7 (<Samsung_S6>) (RA) 802.11   39     Acknowledgement, Flags=........C
  29801 1705.601436    15:10:11.558767    Cisco-Li_72:35:d9     SamsungE_2e:4e:b7     802.11   55     Deauthentication, SN=1521, FN=0, Flags=........C
  29802 1705.601539    15:10:11.558870                          Cisco-Li_72:35:d9 (<EA3500>) (RA) 802.11   39     Acknowledgement, Flags=...P....C
  29803 1705.602320    15:10:11.559651    SamsungE_2e:4e:b7     Broadcast             802.11   158    Probe Request, SN=699, FN=0, Flags=........C, SSID=JH5
  29804 1705.602945    15:10:11.560276    Cisco-Li_72:35:d9     SamsungE_2e:4e:b7     802.11   201    Probe Response, SN=1522, FN=0, Flags=........C, BI=100, SSID=JH5
  29805 1705.603048    15:10:11.560379                          Cisco-Li_72:35:d9 (<EA3500>) (RA) 802.11   39     Acknowledgement, Flags=........C
  29806 1705.622390    15:10:11.579721    SamsungE_2e:4e:b7     Broadcast             802.11   158    Probe Request, SN=700, FN=0, Flags=........C, SSID=JH5
  29807 1705.622937    15:10:11.580268    Cisco-Li_72:35:d9     SamsungE_2e:4e:b7     802.11   201    Probe Response, SN=1523, FN=0, Flags=........C, BI=100, SSID=JH5
  29808 1705.623045    15:10:11.580376                          Cisco-Li_72:35:d9 (<EA3500>) (RA) 802.11   39     Acknowledgement, Flags=........C
  29809 1705.644527    15:10:11.601858    SamsungE_2e:4e:b7     Broadcast             802.11   158    Probe Request, SN=701, FN=0, Flags=........C, SSID=JH5
  29810 1705.664758    15:10:11.622089    SamsungE_2e:4e:b7     Broadcast             802.11   158    Probe Request, SN=702, FN=0, Flags=........C, SSID=JH5
  29811 1705.700072    15:10:11.657403    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1524, FN=0, Flags=........C, BI=100, SSID=JH5
  29812 1705.802475    15:10:11.759806    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1525, FN=0, Flags=........C, BI=100, SSID=JH5
  29813 1705.904877    15:10:11.862208    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1526, FN=0, Flags=........C, BI=100, SSID=JH5
  29814 1706.007272    15:10:11.964603    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1527, FN=0, Flags=........C, BI=100, SSID=JH5
  29815 1706.109652    15:10:12.066983    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1528, FN=0, Flags=........C, BI=100, SSID=JH5
  29816 1706.212019    15:10:12.169350    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1529, FN=0, Flags=........C, BI=100, SSID=JH5
  29817 1706.314550    15:10:12.271881    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1530, FN=0, Flags=........C, BI=100, SSID=JH5
  29818 1706.416922    15:10:12.374253    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1531, FN=0, Flags=........C, BI=100, SSID=JH5
  29819 1706.519340    15:10:12.476671    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1532, FN=0, Flags=........C, BI=100, SSID=JH5
  29820 1706.621740    15:10:12.579071    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1533, FN=0, Flags=........C, BI=100, SSID=JH5
  29821 1706.724007    15:10:12.681338    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1534, FN=0, Flags=........C, BI=100, SSID=JH5
  29822 1706.826527    15:10:12.783858    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1535, FN=0, Flags=........C, BI=100, SSID=JH5
  29823 1706.928798    15:10:12.886129    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1536, FN=0, Flags=........C, BI=100, SSID=JH5
  29824 1706.956814    15:10:12.914145    SamsungE_2e:4e:b7     Broadcast             802.11   155    Probe Request, SN=734, FN=0, Flags=........C, SSID=Broadcast
  29825 1706.957408    15:10:12.914739    Cisco-Li_72:35:d9     SamsungE_2e:4e:b7     802.11   201    Probe Response, SN=1537, FN=0, Flags=........C, BI=100, SSID=JH5
  29826 1706.957513    15:10:12.914844                          Cisco-Li_72:35:d9 (<EA3500>) (RA) 802.11   39     Acknowledgement, Flags=........C
  29827 1706.996100    15:10:12.953431    SamsungE_2e:4e:b7     Broadcast             802.11   155    Probe Request, SN=735, FN=0, Flags=........C, SSID=Broadcast
  29828 1706.996775    15:10:12.954106    Cisco-Li_72:35:d9     SamsungE_2e:4e:b7     802.11   201    Probe Response, SN=1538, FN=0, Flags=........C, BI=100, SSID=JH5
  29829 1706.996880    15:10:12.954211                          Cisco-Li_72:35:d9 (<EA3500>) (RA) 802.11   39     Acknowledgement, Flags=........C
  29830 1707.031325    15:10:12.988656    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1539, FN=0, Flags=........C, BI=100, SSID=JH5
  29831 1707.037740    15:10:12.995071    SamsungE_2e:4e:b7     Broadcast             802.11   155    Probe Request, SN=736, FN=0, Flags=........C, SSID=Broadcast
  29832 1707.038274    15:10:12.995605    Cisco-Li_72:35:d9     SamsungE_2e:4e:b7     802.11   201    Probe Response, SN=1540, FN=0, Flags=........C, BI=100, SSID=JH5
  29833 1707.038421    15:10:12.995752    Cisco-Li_72:35:d9     SamsungE_2e:4e:b7     802.11   201    Probe Response, SN=1540, FN=0, Flags=....R...C, BI=100, SSID=JH5
  29834 1707.077915    15:10:13.035246    SamsungE_2e:4e:b7     Broadcast             802.11   155    Probe Request, SN=737, FN=0, Flags=........C, SSID=Broadcast
  29835 1707.078337    15:10:13.035668    Cisco-Li_72:35:d9     SamsungE_2e:4e:b7     802.11   201    Probe Response, SN=1541, FN=0, Flags=........C, BI=100, SSID=JH5
  29836 1707.078700    15:10:13.036031    Cisco-Li_72:35:d9     SamsungE_2e:4e:b7     802.11   201    Probe Response, SN=1541, FN=0, Flags=....R...C, BI=100, SSID=JH5
  29837 1707.133702    15:10:13.091033    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1542, FN=0, Flags=........C, BI=100, SSID=JH5
  29838 1707.236116    15:10:13.193447    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1543, FN=0, Flags=........C, BI=100, SSID=JH5
  29839 1707.338511    15:10:13.295842    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1544, FN=0, Flags=........C, BI=100, SSID=JH5
  29840 1707.440898    15:10:13.398229    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1545, FN=0, Flags=........C, BI=100, SSID=JH5
  29841 1707.543306    15:10:13.500637    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1546, FN=0, Flags=........C, BI=100, SSID=JH5
  29842 1707.645706    15:10:13.603037    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1547, FN=0, Flags=........C, BI=100, SSID=JH5
  29843 1707.748103    15:10:13.705434    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1548, FN=0, Flags=........C, BI=100, SSID=JH5
  29844 1707.850483    15:10:13.807814    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1549, FN=0, Flags=........C, BI=100, SSID=JH5
  29845 1707.952899    15:10:13.910230    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1550, FN=0, Flags=........C, BI=100, SSID=JH5
  29846 1708.055292    15:10:14.012623    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1551, FN=0, Flags=........C, BI=100, SSID=JH5
  29847 1708.157756    15:10:14.115087    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1552, FN=0, Flags=........C, BI=100, SSID=JH5
  29848 1708.260169    15:10:14.217500    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1553, FN=0, Flags=........C, BI=100, SSID=JH5
  29849 1708.362429    15:10:14.319760    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1554, FN=0, Flags=........C, BI=100, SSID=JH5
  29850 1708.464968    15:10:14.422299    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1555, FN=0, Flags=........C, BI=100, SSID=JH5
  29851 1708.567360    15:10:14.524691    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1556, FN=0, Flags=........C, BI=100, SSID=JH5
  29852 1708.669780    15:10:14.627111    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1557, FN=0, Flags=........C, BI=100, SSID=JH5
  29853 1708.772158    15:10:14.729489    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1558, FN=0, Flags=........C, BI=100, SSID=JH5
  29854 1708.874538    15:10:14.831869    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1559, FN=0, Flags=........C, BI=100, SSID=JH5
  29855 1708.976947    15:10:14.934278    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1560, FN=0, Flags=........C, BI=100, SSID=JH5
  29856 1709.079223    15:10:15.036554    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1561, FN=0, Flags=........C, BI=100, SSID=JH5
  29857 1709.181741    15:10:15.139072    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1562, FN=0, Flags=........C, BI=100, SSID=JH5
  29858 1709.284141    15:10:15.241472    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1563, FN=0, Flags=........C, BI=100, SSID=JH5
  29859 1709.303582    15:10:15.260913    SamsungE_2e:4e:b7     Broadcast             802.11   158    Probe Request, SN=742, FN=0, Flags=........C, SSID=JH5
  29860 1709.304177    15:10:15.261508    Cisco-Li_72:35:d9     SamsungE_2e:4e:b7     802.11   201    Probe Response, SN=1564, FN=0, Flags=........C, BI=100, SSID=JH5
  29861 1709.304281    15:10:15.261612                          Cisco-Li_72:35:d9 (<EA3500>) (RA) 802.11   39     Acknowledgement, Flags=........C
  29862 1709.304792    15:10:15.262123                          Broadcom_04:4e:b7 (<Broadcom>) (RA) 802.11   39     Clear-to-send, Flags=........C
  29863 1709.350311    15:10:15.307642    SamsungE_2e:4e:b7     Cisco-Li_72:35:d9     802.11   70     Authentication, SN=743, FN=0, Flags=........C
  29864 1709.350414    15:10:15.307745                          SamsungE_2e:4e:b7 (<Samsung_S6>) (RA) 802.11   39     Acknowledgement, Flags=........C
  29865 1709.351020    15:10:15.308351    Cisco-Li_72:35:d9     SamsungE_2e:4e:b7     802.11   59     Authentication, SN=1565, FN=0, Flags=........C
  29866 1709.351086    15:10:15.308417                          Cisco-Li_72:35:d9 (<EA3500>) (RA) 802.11   39     Acknowledgement, Flags=........C
  29867 1709.351357    15:10:15.308688    SamsungE_2e:4e:b7     Cisco-Li_72:35:d9     802.11   167    Association Request, SN=744, FN=0, Flags=........C, SSID=JH5
  29868 1709.351458    15:10:15.308789                          SamsungE_2e:4e:b7 (<Samsung_S6>) (RA) 802.11   39     Acknowledgement, Flags=........C
  29869 1709.373708    15:10:15.331039    Cisco-Li_72:35:d9     SamsungE_2e:4e:b7     802.11   157    Association Response, SN=1566, FN=0, Flags=........C
  29870 1709.373775    15:10:15.331106                          Cisco-Li_72:35:d9 (<EA3500>) (RA) 802.11   39     Acknowledgement, Flags=........C
  29871 1709.381598    15:10:15.338929    Cisco-Li_72:35:d9     SamsungE_2e:4e:b7     EAPOL    185    Key (Message 1 of 4)
  29872 1709.381706    15:10:15.339037                          Cisco-Li_72:35:d9 (<EA3500>) (RA) 802.11   39     Acknowledgement, Flags=........C
  29873 1709.386537    15:10:15.343868    Cisco-Li_72:35:d9     Broadcast             802.11   207    Beacon frame, SN=1567, FN=0, Flags=........C, BI=100, SSID=JH5
  29874 1709.398795    15:10:15.356126    SamsungE_2e:4e:b7     Cisco-Li_72:35:d9     EAPOL    184    Key (Message 2 of 4)
  29875 1709.398902    15:10:15.356233                          SamsungE_2e:4e:b7 (<Samsung_S6>) (RA) 802.11   39     Acknowledgement, Flags=........C
  29876 1709.401074    15:10:15.358405    Cisco-Li_72:35:d9     SamsungE_2e:4e:b7     EAPOL    241    Key (Message 3 of 4)
  29877 1709.401182    15:10:15.358513                          Cisco-Li_72:35:d9 (<EA3500>) (RA) 802.11   39     Acknowledgement, Flags=........C
  29878 1709.407586    15:10:15.364917    SamsungE_2e:4e:b7     Cisco-Li_72:35:d9     EAPOL    162    Key (Message 4 of 4)

Hope this can help.

comment:38 Changed 10 months ago by anonymous

Hi,

I also have issues with my ea4500. Just had a look at my stock bootlog, and as far as I can see, the stock fw uses ap8x module instead of mwl8k. I don't really see any package definition for ap8x. any thoughts what ap8x is?

~ # lsmod                                                                       
Module                  Size  Used by    Tainted: P                             
usb_libusual            8021  0                                                 
ehci_hcd               29681  0                                                 
usbcore               101523  3 usb_libusual,ehci_hcd                           
ap8x                 2836073  1                                                 
nf_nat_ftp              1120  0                                                 
nf_conntrack_ftp        4497  1 nf_nat_ftp                                      
nls_iso8859_1           2934  0                                                 
nls_cp437               4466  0                                                 
sd_mod                 23819  0                                                 
scsi_mod               66170  1 sd_mod                                          
orion_wdt               5567  0                                                 
mod_bdutil             16566  2                                                 

comment:39 Changed 10 months ago by wooshcz@…

I have rebuilt the hostapd with eapol_key_timeout_subseq = 10s yesterday, but the timeouts/drops did not disappear. The issue persists on two Android phones - OnePlus X and LG Nexus 5X. Both devices behave a bit differently. It seems that the OnePlus now works almost without a glitch, but the Nexus' WiFi still timeouts and stops working completely for a few minutes.

I'm running build 49871 with modified hostapd since yesterday. I'll try to post more info after some more testing.

comment:40 Changed 10 months ago by lordgilman

Ok, did some more testing with stock hostapd but wpa_group_rekey turned down to 15 seconds. I classified the rekeys as bad (where it exhausts all of the rekey timeouts and disconnects), good (rekeys on the first try) and slow (takes more than one rekey).

The baseline:
Bad: 5 (12%)
Good: 18 (44%)
Slow: 18 (44%)

While doing this test I noticed that it seemed like a timeout that was going to be bad (disconnect) might turn into a slow rekey if data was sent over the network. So I tried the test again, but with video streaming on the phone so there would be constant data being sent:

Constant data:
Bad: 0
Good: 25 (77%)
Slow: 9 (26%)

So a much better improvement. Seems to be related to some sort of buffering on the phone - something about the AP + the phone is making it aggressively buffer data and not wake up to respond to these EAPOLs. I might try to see if disconnects keep happening without any WPA encryption at all next. I did dig around in the offending phone and there isn't any sort of low power or power saving functionality enabled that I could see causing it to buffer like this.

comment:41 Changed 10 months ago by thx1111

I am seeing a problem with the EA3500 which might be related or have the same underlying cause. For what it's worth, I am looking at this from a different perspective, so might be useful. I have several laptops that associate with the EA3500 which seem to work normally, but then I have one, a Toshiba Satellite running a Realtek RTL8188CE using the rtl8192ce and nl80211 drivers, which reacts badly. I note that the dmesg log has
[ 11.638789] ieee80211 phy0: Selected rate control algorithm 'rtl_rc'
and I'm not sure where that rate control is operating, in the firmware, or in some kernel module, or in userspace.

The problem is easiest to see running ping from a machine with a wire connection to the access point, pinging the laptop. Every four to eight seconds, the ping response hangs for about four seconds, and then all the ping replies are returned in a burst. No pings are dropped. On the access point, "iw wlan0 station dump" shows "tx retries: 0" and "tx failed: 0". Running tcpdump on the laptop, it seems to respond immediately whenever it receives an echo request. It just does not get the request during the "hangs". But running tcpdump on the access point, the echo requests are seen passing through wlan0 at regular intervals. I have not looked at the actual RF, so I don't know if the packets are really going over the air or not. Still, it is as if there were a buffer of echo requests filling-up at the access point, and then "dumping" after four seconds or so.

Now, it seems there is an effective and inexplicable workaround for this periodic "hang". If I run ping on the *laptop*, and at the same time ping from the remote machine, the ping hangs at the remote machine completely disappear, and all the ping times average around 1ms.

The EA3500 is running the Marvell 88W8366 Integrated MAC/Baseband MIMO SoC with the 88W8063 MIMO RF Transceiver, and the driver is the mwl8k, which then depends upon mac80211 and cfg80211, and then upon the compat module. The 88W8366 firmware does its own rate control. It is hard to say if the "problem" is in the access point or in the laptop, since they mostly act badly together. But I did try the same ping test using the older Belkin N1, "F5D8231-4 v2" radio, which also has a Marvel chip set, the 88W8361, but running their own driver. There is a similar effect, except that the "hangs" are all on the order of about 900ms instead of 4000ms, and still completely disappear when running ping from the laptop. Perhaps there is some common problem in the Marvell firmware?

I hope all that might spark some ideas, since my workaround is such a hack.

Add Comment

Modify Ticket

Action
as new .
Author


E-mail address and user name can be saved in the Preferences.

 
Note: See TracTickets for help on using tickets.