Debug 802.1x port stuck "IDLE"

Unanswered Question
Aug 25th, 2010

Hello,

I have setup 802.1x and it seems to work most of the time but once in a while the port gets stuck in an IDLE state.

show dot1x int fa0/10
Supplicant MAC <Not Applicable>
AuthSM State          = CONNECTING
BendSM State          = IDLE
Posture               = N/A
   ReAuthPeriod      = None (From Authentication Server)
   ReAuthAction      = N/A
   TimeToNextReauth  = N/A
PortStatus            = UNAUTHORIZED
MaxReq                = 2
MaxAuthReq            = 2
HostMode              = Single
Port Control          = Auto
ControlDirection      = Both
QuietPeriod           = 60 Seconds
Re-authentication     = Enabled
ReAuthPeriod          = From Authentication Server
ServerTimeout         = 10 Seconds
SuppTimeout           = 10 Seconds
TxPeriod              = 10 Seconds
Guest-Vlan            = 20
AuthFail-Vlan         = 20
AuthFail-Max-Attempts = 2

I dont know what could be causing the problem so I enabled debug dot1x all to see whats going on.  However I cannot figure out what the problem is.  Could a bug in the NIC driver cause the port to hang in an IDLE state?  Once a user logs into the system it re-authenticates and come out of the IDLE state but the system itself was not able to connect to the network.

017377: Aug 25 20:08:39.414: dot1x-sm:Fa0/8:0000.0000.0000:dot1x_process_txWhen_
expire called
017378: Aug 25 20:08:39.414:     dot1x_auth Fa0/8: during state auth_connecting,
got event 19(txWhen_expire)
017379: Aug 25 20:08:39.414: @@@ dot1x_auth Fa0/8: auth_connecting -> auth_conne
cting
017380: Aug 25 20:08:39.414: dot1x-sm:Fa0/8:0000.0000.0000:auth_connecting_conne
cting_action called
017381: Aug 25 20:08:39.414: dot1x-sm:dot1x_auth_connecting_action:0000.0000.000
0 auth_count=4 exceeded max auth count=3

017382: Aug 25 20:08:39.414: dot1x-ev:dot1x_post_message_to_auth_sm: Skipping tx
for req_id for default supplicant

017383: Aug 25 20:08:46.282: dot1x-sm:Fa0/11:0000.0000.0000:dot1x_process_txWhen
_expire called
017384: Aug 25 20:08:46.282:     dot1x_auth Fa0/11: during state auth_connecting
, got event 19(txWhen_expire)
017385: Aug 25 20:08:46.282: @@@ dot1x_auth Fa0/11: auth_connecting -> auth_conn
ecting
017386: Aug 25 20:08:46.282: dot1x-sm:Fa0/11:0000.0000.0000:auth_connecting_conn
ecting_action called
017387: Aug 25 20:08:46.282: dot1x-ev:dot1x_post_message_to_auth_sm: Skipping tx
for req_id for default supplicant

017388: Aug 25 20:08:48.070: dot1x-sm:Fa0/10:0000.0000.0000:dot1x_process_txWhen
_expire called
017389: Aug 25 20:08:48.070:     dot1x_auth Fa0/10: during state auth_connecting
, got event 19(txWhen_expire)
017390: Aug 25 20:08:48.070: @@@ dot1x_auth Fa0/10: auth_connecting -> auth_conn
ecting
017391: Aug 25 20:08:48.070: dot1x-sm:Fa0/10:0000.0000.0000:auth_connecting_conn
ecting_action called
017392: Aug 25 20:08:48.070: dot1x-ev:dot1x_post_message_to_auth_sm: Tx for req_
id for supplicant 0000.0000.0000

017393: Aug 25 20:08:48.070: dot1x-ev:Transmitting an EAPOL frame on FastEtherne
t0/10
017394: Aug 25 20:08:48.070: dot1x-packet:Tx EAP-Request(Id), id 8, ver 1, len 5
(Fa0/10)
017395: Aug 25 20:08:48.074: dot1x-registry:registry:dot1x_ether_macaddr called
017396: Aug 25 20:08:48.074: dot1x-packet:Tx sa=0005.dcc1.52ca, da=0180.c200.000
3, et 888E (Fa0/10)
017397: Aug 25 20:08:49.414: dot1x-sm:Fa0/8:0000.0000.0000:dot1x_process_txWhen_
expire called
017398: Aug 25 20:08:49.414:     dot1x_auth Fa0/8: during state auth_connecting,
got event 19(txWhen_expire)
017399: Aug 25 20:08:49.414: @@@ dot1x_auth Fa0/8: auth_connecting -> auth_conne
cting
017400: Aug 25 20:08:49.414: dot1x-sm:Fa0/8:0000.0000.0000:auth_connecting_conne
cting_action called
017401: Aug 25 20:08:49.414: dot1x-ev:dot1x_post_message_to_auth_sm: Skipping tx
for req_id for default supplicant

017402: Aug 25 20:08:56.282: dot1x-sm:Fa0/11:0000.0000.0000:dot1x_process_txWhen
_expire called
017403: Aug 25 20:08:56.282:     dot1x_auth Fa0/11: during state auth_connecting
, got event 19(txWhen_expire)
017404: Aug 25 20:08:56.282: @@@ dot1x_auth Fa0/11: auth_connecting -> auth_conn
ecting
017405: Aug 25 20:08:56.282: dot1x-sm:Fa0/11:0000.0000.0000:auth_connecting_conn
ecting_action called
017406: Aug 25 20:08:56.282: dot1x-sm:dot1x_auth_connecting_action:0000.0000.000
0 auth_count=4 exceeded max auth count=3

017407: Aug 25 20:08:56.282: dot1x-ev:dot1x_post_message_to_auth_sm: Skipping tx
for req_id for default supplicant

017408: Aug 25 20:08:58.070: dot1x-sm:Fa0/10:0000.0000.0000:dot1x_process_txWhen
_expire called
017409: Aug 25 20:08:58.070:     dot1x_auth Fa0/10: during state auth_connecting
, got event 19(txWhen_expire)
017410: Aug 25 20:08:58.070: @@@ dot1x_auth Fa0/10: auth_connecting -> auth_conn
ecting
017411: Aug 25 20:08:58.070: dot1x-sm:Fa0/10:0000.0000.0000:auth_connecting_conn
ecting_action called
017412: Aug 25 20:08:58.070: dot1x-ev:dot1x_post_message_to_auth_sm: Tx for req_
id for supplicant 0000.0000.0000

017413: Aug 25 20:08:58.070: dot1x-ev:Transmitting an EAPOL frame on FastEtherne
t0/10
017414: Aug 25 20:08:58.074: dot1x-packet:Tx EAP-Request(Id), id 8, ver 1, len 5
(Fa0/10)
017415: Aug 25 20:08:58.074: dot1x-registry:registry:dot1x_ether_macaddr called
017416: Aug 25 20:08:58.074: dot1x-packet:Tx sa=0005.dcc1.52ca, da=0180.c200.000
3, et 888E (Fa0/10)no
017417: Aug 25 20:08:59.414: dot1x-sm:Fa0/8:0000.0000.0000:dot1x_process_txWhen_
expire called
017418: Aug 25 20:08:59.414:     dot1x_auth Fa0/8: during state auth_connecting,
got event 19(txWhen_expire)
017419: Aug 25 20:08:59.414: @@@ dot1x_auth Fa0/8: auth_connecting -> auth_conne
cting
017420: Aug 25 20:08:59.414: dot1x-sm:Fa0/8:0000.0000.0000:auth_connecting_conne
cting_action called
017421: Aug 25 20:08:59.414: dot1x-ev:dot1x_post_message_to_auth_sm: Skipping tx
for req_id for default supplicant

I have this problem too.
0 votes
  • 1
  • 2
  • 3
  • 4
  • 5
Overall Rating: 0 (0 ratings)
Loading.
yaplej Mon, 08/30/2010 - 09:28

Anyone else seen this with Broadcom NICs?  I am thinking its a bug in the driver but am not 100% sure of that.  I can turn the system off for a moment and then it works fine.

Just wanted to see if anyone else had seen this or could tell from the debug if its some other issue.

Thanks.

Actions

This Discussion

Related Content