intermittent voice problems

Unanswered Question
May 12th, 2010

Hi,

we have an 4402 controller with code 4.2.176 that have configured 2 WLANs, one for voice and other for data. We are only getting problems with the voice WLAN (connection lost and voice losses also).

We are getting problems in all phones and in aleatory locations, so it's not an AP specific problem. I have checked and all the phones appear as associated and authenticated except one.

As this was the only phone that I could see some problem I did a debug on it (the output is below). The only difference between this and the other phones it's that when I check is state have the Policy Manager configured as DHCP_REQ, the others are as RUN. What can cause this and how can solve it?

Beside this what can cause the problems in the voice WLAN? Other thing that it's strange it's that we have configured AP Groups for some tests at that time we had a voice WLAN, data WLAN and a guest WLAN. In the AP Group policy in use in all the APs we added the data interface and the voice interface, but now strangely I only see there the voice interface configured. More strange it's that the data WLAN it's working fine, but the voice WLAN it's with this intermittent problems. Without the data interface in the AP Group the PCs should be able to connect to the data WLAN right?

Someone have any ideas of what can be causing this?

_____________________________________________________________________________________________________________________
(Cisco Controller) >Wed May 12 19:26:00 2010: 00:01:e3:8c:b2:49 0.0.0.0 DHCP_REQD (7) DHCP Policy timeout
Wed May 12 19:26:00 2010: 00:01:e3:8c:b2:49 0.0.0.0 DHCP_REQD (7) Pem timed out, Try to delete client in 10 secs.
Wed May 12 19:26:00 2010: 00:01:e3:8c:b2:49 Scheduling deletion of Mobile Station:  (callerId: 12) in 10 seconds
Wed May 12 19:26:10 2010: 00:01:e3:8c:b2:49 apfMsExpireCallback (apf_ms.c:433) Expiring Mobile!
Wed May 12 19:26:10 2010: 00:01:e3:8c:b2:49 apfMsExpireMobileStation (apf_ms.c:4224) Changing state for mobile 00:01:e3:8c:b2:49 on AP

00:1a:a2:fa:a5:40 from Associated to Disassociated
Wed May 12 19:26:10 2010: 00:01:e3:8c:b2:49 Scheduling deletion of Mobile Station:  (callerId: 45) in 10 seconds
Wed May 12 19:26:20 2010: 00:01:e3:8c:b2:49 apfMsExpireCallback (apf_ms.c:433) Expiring Mobile!
Wed May 12 19:26:20 2010: 00:01:e3:8c:b2:49 Sent Deauthenticate to mobile on BSSID 00:1a:a2:fa:a5:40 slot 0(caller apf_ms.c:4294)
Wed May 12 19:26:20 2010: 00:01:e3:8c:b2:49 apfMsExpireMobileStation (apf_ms.c:4330) Changing state for mobile 00:01:e3:8c:b2:49 on AP

00:1a:a2:fa:a5:40 from Disassociated to Idle
Wed May 12 19:26:20 2010: 00:01:e3:8c:b2:49 0.0.0.0 DHCP_REQD (7) Deleted mobile LWAPP rule on AP [00:1a:a2:fa:a5:40]
Wed May 12 19:26:20 2010: 00:01:e3:8c:b2:49 Deleting mobile on AP 00:1a:a2:fa:a5:40(0)
Wed May 12 19:26:20 2010: 00:01:e3:8c:b2:49 0.0.0.0 Removed NPU entry.
Wed May 12 19:26:21 2010: 00:01:e3:8c:b2:49 Adding mobile on LWAPP AP 00:1a:a2:fa:a5:40(0)
Wed May 12 19:26:21 2010: 00:01:e3:8c:b2:49 Association received from mobile on AP 00:1a:a2:fa:a5:40
Wed May 12 19:26:21 2010: 00:01:e3:8c:b2:49 Applying site-specific override for station 00:01:e3:8c:b2:49 - vapId 3, site 'WLANS_NO_GUEST',

interface 'vp-hrm'
Wed May 12 19:26:21 2010: 00:01:e3:8c:b2:49 0.0.0.0 START (0) Changing ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller

apf_policy.c:1099)
Wed May 12 19:26:21 2010: 00:01:e3:8c:b2:49 STA - rates (3): 132 139 150 0 0 0 0 0 0 0 0 0 0 0 0 0
Wed May 12 19:26:21 2010: 00:01:e3:8c:b2:49 STA - rates (11): 132 139 150 12 18 24 36 48 72 96 108 0 0 0 0 0
Wed May 12 19:26:21 2010: 00:01:e3:8c:b2:49 Processing WPA IE type 221, length 22 for mobile 00:01:e3:8c:b2:49
Wed May 12 19:26:21 2010: 00:01:e3:8c:b2:49 0.0.0.0 START (0) Initializing policy
Wed May 12 19:26:21 2010: 00:01:e3:8c:b2:49 0.0.0.0 START (0) Change state to AUTHCHECK (2) last state AUTHCHECK (2)
Wed May 12 19:26:21 2010: 00:01:e3:8c:b2:49 0.0.0.0 AUTHCHECK (2) Change state to 8021X_REQD (3) last state 8021X_REQD (3)
Wed May 12 19:26:21 2010: 00:01:e3:8c:b2:49 0.0.0.0 8021X_REQD (3) Plumbed mobile LWAPP rule on AP 00:1a:a2:fa:a5:40
Wed May 12 19:26:21 2010: 00:01:e3:8c:b2:49 apfPemAddUser2 (apf_policy.c:212) Changing state for mobile 00:01:e3:8c:b2:49 on AP 00:1a:a2:fa:a5:40

from Idle to Associated
Wed May 12 19:26:21 2010: 00:01:e3:8c:b2:49 Stopping deletion of Mobile Station: (callerId: 48)
Wed May 12 19:26:21 2010: 00:01:e3:8c:b2:49 Sending Assoc Response to station on BSSID 00:1a:a2:fa:a5:40 (status 0)
Wed May 12 19:26:21 2010: 00:01:e3:8c:b2:49 apfProcessAssocReq (apf_80211.c:3885) Changing state for mobile 00:01:e3:8c:b2:49 on AP

00:1a:a2:fa:a5:40 from Associated to Associated
Wed May 12 19:26:21 2010: 00:01:e3:8c:b2:49 Creating a PKC PMKID Cache entry for station 00:01:e3:8c:b2:49 (RSN 0)
Wed May 12 19:26:21 2010: 00:01:e3:8c:b2:49 Initiating WPA PSK to mobile 00:01:e3:8c:b2:49
Wed May 12 19:26:21 2010: 00:01:e3:8c:b2:49 dot1x - moving mobile 00:01:e3:8c:b2:49 into Force Auth state
Wed May 12 19:26:21 2010: 00:01:e3:8c:b2:49 Skipping EAP-Success to mobile 00:01:e3:8c:b2:49
Wed May 12 19:26:21 2010: 00:01:e3:8c:b2:49 Sending EAPOL-Key Message to mobile 00:01:e3:8c:b2:49
                                                                                                    state INITPMK (message 1), replay counter

00.00.00.00.00.00.00.00
Wed May 12 19:26:21 2010: 00:01:e3:8c:b2:49 Received EAPOL-Key from mobile 00:01:e3:8c:b2:49
Wed May 12 19:26:21 2010: 00:01:e3:8c:b2:49 Received EAPOL-key in PKT_START state (message 2) from mobile 00:01:e3:8c:b2:49
Wed May 12 19:26:21 2010: 00:01:e3:8c:b2:49 Stopping retransmission timer for mobile 00:01:e3:8c:b2:49
Wed May 12 19:26:21 2010: 00:01:e3:8c:b2:49 Sending EAPOL-Key Message to mobile 00:01:e3:8c:b2:49
                                                                                                    state PTKINITNEGOTIATING (message 3), replay

counter 00.00.00.00.00.00.00.01
Wed May 12 19:26:21 2010: 00:01:e3:8c:b2:49 802.1x 'timeoutEvt' Timer expired for station 00:01:e3:8c:b2:49
Wed May 12 19:26:21 2010: 00:01:e3:8c:b2:49 Retransmit 1 of EAPOL-Key M3 (length 125) for mobile 00:01:e3:8c:b2:49
Wed May 12 19:26:21 2010: 00:01:e3:8c:b2:49 Received EAPOL-Key from mobile 00:01:e3:8c:b2:49
Wed May 12 19:26:21 2010: 00:01:e3:8c:b2:49 Received EAPOL-key in PTKINITNEGOTIATING state (message 4) from mobile 00:01:e3:8c:b2:49
Wed May 12 19:26:21 2010: 00:01:e3:8c:b2:49 0.0.0.0 8021X_REQD (3) Change state to L2AUTHCOMPLETE (4) last state L2AUTHCOMPLETE (4)
Wed May 12 19:26:21 2010: 00:01:e3:8c:b2:49 0.0.0.0 L2AUTHCOMPLETE (4) State Update from Mobility-Incomplete to Mobility-Complete, mobility

role=Local
Wed May 12 19:26:21 2010: 00:01:e3:8c:b2:49 0.0.0.0 L2AUTHCOMPLETE (4) Plumbed mobile LWAPP rule on AP 00:1a:a2:fa:a5:40
Wed May 12 19:26:21 2010: 00:01:e3:8c:b2:49 0.0.0.0 L2AUTHCOMPLETE (4) pemAdvanceState2 4237, Adding TMP rule
Wed May 12 19:26:21 2010: 00:01:e3:8c:b2:49 0.0.0.0 L2AUTHCOMPLETE (4) Adding Fast Path rule
  type = Airespace AP - Learn IP address
  on AP 00:1a:a2:fa:a5:40, slot 0, interface = 1, QOS = 2
  ACL Id = 255, Jumbo Frames = NO, 802.1P = 0, DSCP = 0, TokenID = 5006
Wed May 12 19:26:21 2010: 00:01:e3:8c:b2:49 0.0.0.0 L2AUTHCOMPLETE (4) Successfully plumbed mobile rule (ACL ID 255)
Wed May 12 19:26:21 2010: 00:01:e3:8c:b2:49 0.0.0.0 L2AUTHCOMPLETE (4) Change state to DHCP_REQD (7) last state DHCP_REQD (7)
Wed May 12 19:26:21 2010: 00:01:e3:8c:b2:49 0.0.0.0 DHCP_REQD (7) pemAdvanceState2 4253, Adding TMP rule
Wed May 12 19:26:21 2010: 00:01:e3:8c:b2:49 0.0.0.0 DHCP_REQD (7) Replacing Fast Path rule
  type = Airespace AP - Learn IP address
  on AP 00:1a:a2:fa:a5:40, slot 0, interface = 1, QOS = 2
  ACL Id = 255, Jumbo Frames = NO, 802.1P = 0, DSCP = 0, TokenID = 5006
Wed May 12 19:26:21 2010: 00:01:e3:8c:b2:49 0.0.0.0 DHCP_REQD (7) Successfully plumbed mobile rule (ACL ID 255)
Wed May 12 19:26:21 2010: 00:01:e3:8c:b2:49 Stopping retransmission timer for mobile 00:01:e3:8c:b2:49
Wed May 12 19:26:21 2010: 00:01:e3:8c:b2:49 Sending EAPOL-Key Message to mobile 00:01:e3:8c:b2:49
                                                                                                    state PTKINITDONE (message 5 - group), replay

counter 00.00.00.00.00.00.00.03
Wed May 12 19:26:21 2010: 00:01:e3:8c:b2:49 Sent EAPOL-Key M5 for mobile 00:01:e3:8c:b2:49
Wed May 12 19:26:21 2010: 00:01:e3:8c:b2:49 0.0.0.0 Added NPU entry of type 9
Wed May 12 19:26:21 2010: 00:01:e3:8c:b2:49 Sent an XID frame
Wed May 12 19:26:21 2010: 00:01:e3:8c:b2:49 0.0.0.0 Added NPU entry of type 9
Wed May 12 19:26:22 2010: 00:01:e3:8c:b2:49 Received EAPOL-Key from mobile 00:01:e3:8c:b2:49
Wed May 12 19:26:22 2010: 00:01:e3:8c:b2:49 Received EAPOL-key in REKEYNEGOTIATING state (message 6) from mobile 00:01:e3:8c:b2:49
Wed May 12 19:26:22 2010: 00:01:e3:8c:b2:49 Stopping retransmission timer for mobile 00:01:e3:8c:b2:49

I have this problem too.
0 votes
  • 1
  • 2
  • 3
  • 4
  • 5
Overall Rating: 0 (0 ratings)
Loading.

Actions

This Discussion