Big delays between an AR5416 AP and its clients

[Gustau Perez Querol]

   This is the environment:

   I'm using an AR5416 card acting as an AP with hostap in 11g mode. I'm 
running g because I did not have time to test the 11n work yet. The box 
is running CURRENT/AMD64 as of Nov 22th.

   These are the symptoms:

   A few days ago I began to see very big delays between the AP and my 
laptop (which has an AR9287 with FreeBSD/AMD64 CURRENT). I tried a 
simple icmp with 1 second between pings. The curious thing is that 
delays increase from 30ms til 100ms (those times are in the same order 
of magnitude of a ping to google) and then they fall til 30ms again. It 
did not work like that before.

   I tested with different clients (an iPhone, a laptop running FreeBSD 
with an Intel 3945, an asus eeePC laptop with windows7 and other 
devices). All of them showed the same behavior.

   Further experiments showed me that the problem appears when any 
iPhone associates with the AP. As soon as the iPhone deassociates the 
other clients see no problems at all. ICMP messages get less than a ms 
to get replied (which are rtt I would expect).

   I'm pasting online at the end of the mail a simple icmp trace where 
you can see how it behaves. It shows increasing  icmp rtt and then 
falling to usable time. Then it increases again.

   This is where I am now:

   I'm tracking kib's git repository (because I'm helping him as a 
tester and bug finder with his work with the GEM/KMS thing, that machine 
has a card giving us a lot of headaches) so I decided to do a bisect to 
find out which commit introduced the bug with the AR5416. Memory served 
me well and I could tell at the end of October it worked fine (we have 
two iphone at home and they worked fine), so it would be something 
introduced in November.

   The bisect lead me to r227364, which is one quite large. I took a 
look at the code, but I'm not used to the ath land.

   I ensured the previous one did well, with two iPhones there, 3 
laptops (2 FreeBSD and one win7), a Wii and a multimedia wifi hard 
drive. It did well. Using the next commit triggered the problem.

   I have a custom r227364 compilation with ATH_DEBUG, AH_DEBUG and 
ATH_GSAPIA there. I also compiled athstat. However now I'm at $WORK and 
I can not test till this afternoon (I'm at +1UTC). I'll test with 
athstats the card's behaviour when the iPhone associates and post back 
to the list.

   I will take a look at the diff of this revision, but I'm not used to 
the ath|wireless code in the kernel, so I would say I will not find 
anything interesting. However I'll spend some time (4 eyes see more than 
two, they say).

   Any additional test or if you have any idea where the problem gets 
introduced so I can take at the code, please let me know.

   Gustau

******************************************************
  bytes from 192.168.1.100: icmp_seq=15 ttl=64 time=0.946 ms
64 bytes from 192.168.1.100: icmp_seq=16 ttl=64 time=1.016 ms
64 bytes from 192.168.1.100: icmp_seq=17 ttl=64 time=1.011 ms
64 bytes from 192.168.1.100: icmp_seq=18 ttl=64 time=1.040 ms
64 bytes from 192.168.1.100: icmp_seq=19 ttl=64 time=0.779 ms
64 bytes from 192.168.1.100: icmp_seq=20 ttl=64 time=0.657 ms
64 bytes from 192.168.1.100: icmp_seq=21 ttl=64 time=0.945 ms
64 bytes from 192.168.1.100: icmp_seq=22 ttl=64 time=88.747 ms
64 bytes from 192.168.1.100: icmp_seq=23 ttl=64 time=109.538 ms
64 bytes from 192.168.1.100: icmp_seq=24 ttl=64 time=29.992 ms
64 bytes from 192.168.1.100: icmp_seq=25 ttl=64 time=0.978 ms
64 bytes from 192.168.1.100: icmp_seq=26 ttl=64 time=74.145 ms
64 bytes from 192.168.1.100: icmp_seq=27 ttl=64 time=97.230 ms
64 bytes from 192.168.1.100: icmp_seq=28 ttl=64 time=17.816 ms
64 bytes from 192.168.1.100: icmp_seq=29 ttl=64 time=41.417 ms
64 bytes from 192.168.1.100: icmp_seq=30 ttl=64 time=62.682 ms
64 bytes from 192.168.1.100: icmp_seq=31 ttl=64 time=84.579 ms
64 bytes from 192.168.1.100: icmp_seq=32 ttl=64 time=107.628 ms
64 bytes from 192.168.1.100: icmp_seq=33 ttl=64 time=27.328 ms
64 bytes from 192.168.1.100: icmp_seq=34 ttl=64 time=50.283 ms
******************************************************