Big delays between an AR5416 AP and its clients

[Gustau Pérez]

On 02/12/2011 03:50, Adrian Chadd wrote:
> Hi,
>
> I've taken a quick peek. There's nothing obviously wrong with that trace.
>
> Can you please redo this with:
>
> * 5 runs?
> * 100 pings a second - ie, ping -i 0.01
> * capture the output of athstats -i ath0 before and after each run, as
> well as during a run
> * let it run for say, 60 seconds at a time.

   I did the test. The files are labeled as:

              athstats_before_ping_runX.txt

    for the counters before a run and:

              athstats_ping_runX.txt

    for the output of athstats 1 during the ping. The tests were made 
while pinging the AR5416 box with:

               ping -i 0.01 -c 6000


    You can download the results from:

          https://www-entel.upc.edu/gus/ath_second_test.tar.gz

    I see little different with the previous test. One that I noticed is 
that no matter how fast (or slow) I ping the box, the frequency of the 
phenomenon  (which is the lattency increasing and then suddenly falling) 
seems to depend on the number of packets received instead of time.

    That can, maybe, give a clue of what is going on. I see that it 
appears to keep increasing for about 10 packets and then the latency 
suddenly falls. It showed the same behavior when using 0.1seg between 
packets, latency increased during 10 packets and then it fell.

   However the minimum value is three orders of magnitude bigger than 
the normal values I get when using a kernel previous to r227364. I would 
say that there's something like a queue being filled, but I'm just 
speculating.

   Of course, as soon as I block the iphone everything goes back to 
normal (too bad this can't be overridden, I can't fetch mail while the 
iphone is blocked)

> Also, once that's done, try it again with this:
>
> wlandebug -i wlan0 +power +input +output +state +assoc +mlme
>
> see if anything interesting pops up at the same time as your latency increases.

    I see nothing particular in my dmesg with wlandebug enabled. I see 
the AR5416 complaining about a beacon off-channel for a MAC I don't know 
about. I also see the iphone's MAC going power save with a message like 
this:

              power save mode on, 2 sta's in ps mode

   I also see all of those messages with a pre r227364 kernel, so I 
would say they are harmless and not related to the issue.

   However, I see these the following entries in my dmesg when using 
r227364:

	Dec  3 16:46:27 harkserver kernel: Timeout while waiting for nf
	to load: AR_PHY_AGC_CONTROL=0x41d1a
	Dec  3 16:46:27 harkserver kernel: Timeout while waiting for nf
	to load: AR_PHY_AGC_CONTROL=0x41d1a

	Dec  3 16:18:27 harkserver kernel: ar5416PerCalibrationN: NF
	calibration didn't finish; delaying CCA
	Dec  3 16:18:27 harkserver kernel: ar5416PerCalibrationN: NF
	calibration didn't finish; delaying CCA

   I don't see those messages with a previous revision because they 
appear to be part of r227364. Those problems appear from time to time, 
could they and the latency increase be related?

   Thanks,

   Gus