Hi experts,
I'm having problems configuring PF in vlan enforcement. I am trying to
authenticate using dot1x but it failovers to mab and albeit I can see in
cisco logs that vlan2 (registration) is assigned but client does not get ip
in vlan 2 range. I have tested with having dot1x disabled too but when I
put user directly on registration vlan after successful login in captive
portal user doesn't get reassigned to vlan 3 and captive portal shows an
error "Unable to detect network connectivity. Try restarting your web
browser or opening a new tab to see if your access has been successfully
enabled. Honestly I haven't been able to run a working installation so far.
I have tried inline and vlan enforcement using Zen all with no success!
There are a few timeout errors in my cisco 2960 logs (I made them bold) but
I made sure that both PF and cisco can see each other. I have also
temporarily disabled PF iptables (iptables -F) and it didn't make any
difference.
Please help me out get PF working as expected.
Thanks
*show authentication sessions interface fastEthernet 0/1*
Interface: FastEthernet0/1
MAC Address: 782b.cbd2.b26e
IP Address: Unknown
User-Name: 782bcbd2b26e
* Status: Authz Failed*
Domain: DATA
Oper host mode: multi-domain
Oper control dir: both
Authorized By: Authentication Server
Vlan Policy: N/A
Session timeout: 10800s (local), Remaining: 10226s
Timeout action: Reauthenticate
Idle timeout: N/A
Common Session ID: C0A864020000005E01C16861
Acct Session ID: 0x000001B5
Handle: 0x1E00005F
*radiusd.log*
Fri Jul 29 18:03:21 2016 : Auth: rlm_perl: Returning vlan 2 to request from
78:2b:cb:d2:b2:6e port 50001
Fri Jul 29 18:03:21 2016 : rlm_perl: PacketFence RESULT RESPONSE CODE: 2 (2
means OK)
Fri Jul 29 18:03:21 2016 : Info: rlm_sql (sql): Closing connection (53):
Hit idle_timeout, was idle for 2182 seconds
Fri Jul 29 18:03:21 2016 : Info: rlm_sql (sql): Closing connection (54):
Hit idle_timeout, was idle for 2182 seconds
Fri Jul 29 18:03:21 2016 : Info: rlm_sql (sql): Opening additional
connection (55), 1 of 64 pending slots used
Fri Jul 29 18:03:21 2016 : Info: rlm_sql (sql): Need 2 more connections to
reach 10 spares
Fri Jul 29 18:03:21 2016 : Info: rlm_sql (sql): Opening additional
connection (56), 1 of 63 pending slots used
Fri Jul 29 18:03:20 2016 : [mac:78:2b:cb:d2:b2:6e] Accepted user: and
returned VLAN 2
Fri Jul 29 18:03:21 2016 : Auth: (65) Login OK: [782bcbd2b26e] (from client
192.168.100.2 port 50001 cli 78:2b:cb:d2:b2:6e)
*packetfence.log*
Jul 29 18:03:21 httpd.aaa(3552) INFO: [mac:78:2b:cb:d2:b2:6e] handling
radius autz request: from switch_ip => (192.168.100.2), connection_type =>
WIRED_MAC_AUTH,switch_mac => (00:26:98:dd:2e:81), mac =>
[78:2b:cb:d2:b2:6e], port => 10001, username => "782bcbd2b26e"
(pf::radius::authorize)
Jul 29 18:03:21 httpd.aaa(3552) INFO: [mac:78:2b:cb:d2:b2:6e] Instantiate
profile default (pf::Portal::ProfileFactory::_from_profile)
Jul 29 18:03:21 httpd.aaa(3552) INFO: [mac:78:2b:cb:d2:b2:6e] is of status
unreg; belongs into registration VLAN (pf::role::getRegistrationRole)
Jul 29 18:03:21 httpd.aaa(3552) INFO: [mac:78:2b:cb:d2:b2:6e]
(192.168.100.2) Added VLAN 2 to the returned RADIUS Access-Accept
(pf::Switch::returnRadiusAccessAccept)
Jul 29 18:03:21 httpd.aaa(3552) INFO: [mac:78:2b:cb:d2:b2:6e]
(192.168.100.2) Added role registration to the returned RADIUS
Access-Accept (pf::Switch::returnRadiusAccessAccept)
*Cisco 2960 IOS 15.0(2)SE10 log of dot1x/mab authentication (tried with IOS
12.55 as well):*
004176: 08:10:32: dot1x-ev(Fa0/1): Interface state changed to UP
004177: 08:10:32: AAA/BIND(000001BD): Bind i/f
004178: 08:10:32: dot1x_auth Fa0/1: initial state auth_initialize has
enter
004179: 08:10:32: dot1x-sm(Fa0/1): 0x8500004E:auth_initialize_enter called
004180: 08:10:32: dot1x_auth Fa0/1: during state auth_initialize, got
event 0(cfg_auto)
004181: 08:10:32: @@@ dot1x_auth Fa0/1: auth_initialize -> auth_disconnected
004182: 08:10:32: dot1x-sm(Fa0/1): 0x8500004E:auth_disconnected_enter called
004183: 08:10:32: dot1x_auth Fa0/1: idle during state auth_disconnected
004184: 08:10:32: @@@ dot1x_auth Fa0/1: auth_disconnected -> auth_restart
004185: 08:10:32: dot1x-sm(Fa0/1): 0x8500004E:auth_restart_enter called
004186: 08:10:32: dot1x-ev(Fa0/1): Sending create new context event to EAP
for 0x8500004E (0000.0000.0000)
004187: 08:10:32: dot1x_auth_bend Fa0/1: initial state
auth_bend_initialize has enter
004188: 08:10:32: dot1x-sm(Fa0/1): 0x8500004E:auth_bend_initialize_enter
called
004189: 08:10:32: dot1x_auth_bend Fa0/1: initial state
auth_bend_initialize has idle
004190: 08:10:32: dot1x_auth_bend Fa0/1: during state
auth_bend_initialize, got event 16383(idle)
004191: 08:10:32: @@@ dot1x_auth_bend Fa0/1: auth_bend_initialize ->
auth_bend_idle
004192: 08:10:32: dot1x-sm(Fa0/1): 0x8500004E:auth_bend_idle_enter called
004193: 08:10:32: dot1x-ev(Fa0/1): Created a client entry (0x8500004E)
004194: 08:10:32: dot1x-ev(Fa0/1): Dot1x authentication started for
0x8500004E (0000.0000.0000)
004195: 08:10:32: dot1x-ev:DOT1X Supplicant not enabled on FastEthernet0/1
004196: 08:10:32: dot1x-sm(Fa0/1): Posting !EAP_RESTART on Client 0x8500004E
004197: 08:10:32: dot1x_auth Fa0/1: during state auth_restart, got
event 6(no_eapRestart)
004198: 08:10:32: @@@ dot1x_auth Fa0/1: auth_restart -> auth_connecting
004199: 08:10:32: dot1x-sm(Fa0/1): 0x8500004E:auth_connecting_enter called
004200: 08:10:32: dot1x-sm(Fa0/1):
0x8500004E:auth_restart_connecting_action called
004201: 08:10:32: dot1x-sm(Fa0/1): Posting RX_REQ on Client 0x8500004E
004202: 08:10:32: dot1x_auth Fa0/1: during state auth_connecting, got
event 10(eapReq_no_reAuthMax)
004203: 08:10:32: @@@ dot1x_auth Fa0/1: auth_connecting ->
auth_authenticating
004204: 08:10:32: dot1x-sm(Fa0/1): 0x8500004E:auth_authenticating_enter
called
004205: 08:10:32: dot1x-sm(Fa0/1):
0x8500004E:auth_connecting_authenticating_action called
004206: 08:10:32: dot1x-sm(Fa0/1): Posting AUTH_START for 0x8500004E
004207: 08:10:32: dot1x_auth_bend Fa0/1: during state auth_bend_idle,
got event 4(eapReq_authStart)
004208: 08:10:32: @@@ dot1x_auth_bend Fa0/1: auth_bend_idle ->
auth_bend_request
004209: 08:10:32: dot1x-sm(Fa0/1): 0x8500004E:auth_bend_request_enter called
004210: 08:10:32: dot1x-ev(Fa0/1): Sending EAPOL packet to group PAE address
004211: 08:10:32: dot1x-ev(Fa0/1): Role determination not required
004212: 08:10:32: dot1x-registry:registry:dot1x_ether_macaddr called
004213: 08:10:32: dot1x-ev(Fa0/1): Sending out EAPOL packet
004214: 08:10:32: EAPOL pak dump Tx
004215: 08:10:32: EAPOL Version: 0x3 type: 0x0 length: 0x0005
004216: 08:10:32: EAP code: 0x1 id: 0x1 length: 0x0005 type: 0x1
004217: 08:10:32: dot1x-packet(Fa0/1): EAPOL packet sent to client
0x8500004E (0000.0000.0000)
004218: 08:10:32: dot1x-sm(Fa0/1): 0x8500004E:auth_bend_idle_request_action
called
004219: 08:10:32: dot1x-ev(Fa0/1): New client notification from AuthMgr for
0x8500004E - 782b.cbd2.b26e
004220: *Mar 1 08:10:32: %AUTHMGR-5-START: Starting 'dot1x' for client
(782b.cbd2.b26e) on Interface Fa0/1 AuditSessionID C0A864020000005C01C1190D
004221: 08:10:32: dot1x-sm(Fa0/1): Posting RESTART on Client 0x8500004E
004222: 08:10:32: dot1x_auth Fa0/1: during state auth_authenticating,
got event 13(restart)
004223: 08:10:32: @@@ dot1x_auth Fa0/1: auth_authenticating -> auth_aborting
004224: 08:10:32: dot1x-sm(Fa0/1): 0x8500004E:auth_authenticating_exit
called
004225: 08:10:32: dot1x-sm(Fa0/1): 0x8500004E:auth_aborting_enter called
004226: 08:10:32: dot1x-sm(Fa0/1):
0x8500004E:auth_authenticating_aborting_action called
004227: 08:10:32: dot1x-sm(Fa0/1): Posting AUTH_ABORT for 0x8500004E
004228: 08:10:32: dot1x_auth_bend Fa0/1: during state
auth_bend_request, got event 1(authAbort)
004229: 08:10:32: @@@ dot1x_auth_bend Fa0/1: auth_bend_request ->
auth_bend_initialize
004230: 08:10:32: dot1x-sm(Fa0/1): 0x8500004E:auth_bend_initialize_enter
called
004231: 08:10:32: dot1x_auth_bend Fa0/1: idle during state
auth_bend_initialize
004232: 08:10:32: @@@ dot1x_auth_bend Fa0/1: auth_bend_initialize ->
auth_bend_idle
004233: 08:10:32: dot1x-sm(Fa0/1): 0x8500004E:auth_bend_idle_enter called
004234: 08:10:32: dot1x-sm(Fa0/1): Posting !AUTH_ABORT on Client 0x8500004E
004235: 08:10:32: dot1x_auth Fa0/1: during state auth_aborting, got
event 20(no_eapolLogoff_no_authAbort)
004236: 08:10:32: @@@ dot1x_auth Fa0/1: auth_aborting -> auth_restart
004237: 08:10:32: dot1x-sm(Fa0/1): 0x8500004E:auth_aborting_exit called
004238: 08:10:32: dot1x-sm(Fa0/1): 0x8500004E:auth_restart_enter called
004239: 08:10:32: dot1x-ev(Fa0/1): Resetting the client 0x8500004E
(782b.cbd2.b26e)
004240: 08:10:32: dot1x-ev(Fa0/1): Sending create new context event to EAP
for 0x8500004E (782b.cbd2.b26e)
004241: 08:10:32: dot1x-sm(Fa0/1): 0x8500004E:auth_aborting_restart_action
called
004242: 08:10:32: dot1x-sm(Fa0/1): Posting !EAP_RESTART on Client 0x8500004E
004243: 08:10:32: dot1x_auth Fa0/1: during state auth_restart, got
event 6(no_eapRestart)
004244: 08:10:32: @@@ dot1x_auth Fa0/1: auth_restart -> auth_connecting
004245: 08:10:32: dot1x-sm(Fa0/1): 0x8500004E:auth_connecting_enter called
004246: 08:10:32: dot1x-sm(Fa0/1):
0x8500004E:auth_restart_connecting_action called
004247: 08:10:32: dot1x-sm(Fa0/1): Posting RX_REQ on Client 0x8500004E
004248: 08:10:32: dot1x_auth Fa0/1: during state auth_connecting, got
event 10(eapReq_no_reAuthMax)
004249: 08:10:32: @@@ dot1x_auth Fa0/1: auth_connecting ->
auth_authenticating
004250: 08:10:32: dot1x-sm(Fa0/1): 0x8500004E:auth_authenticating_enter
called
004251: 08:10:32: dot1x-sm(Fa0/1):
0x8500004E:auth_connecting_authenticating_action called
004252: 08:10:32: dot1x-sm(Fa0/1): Posting AUTH_START for 0x8500004E
004253: 08:10:32: dot1x_auth_bend Fa0/1: during state auth_bend_idle,
got event 4(eapReq_authStart)
004254: 08:10:32: @@@ dot1x_auth_bend Fa0/1: auth_bend_idle ->
auth_bend_request
004255: 08:10:32: dot1x-sm(Fa0/1): 0x8500004E:auth_bend_request_enter called
004256: 08:10:32: dot1x-ev(Fa0/1): Sending EAPOL packet to 782b.cbd2.b26e
004257: 08:10:32: dot1x-ev(Fa0/1): Role determination not required
004258: 08:10:32: dot1x-registry:registry:dot1x_ether_macaddr called
004259: 08:10:32: dot1x-ev(Fa0/1): Sending out EAPOL packet
004260: 08:10:32: EAPOL pak dump Tx
004261: 08:10:32: EAPOL Version: 0x3 type: 0x0 length: 0x0005
004262: 08:10:32: EAP code: 0x1 id: 0x1 length: 0x0005 type: 0x1
004263: 08:10:32: dot1x-packet(Fa0/1): EAPOL packet sent to client
0x8500004E (782b.cbd2.b26e)
004264: 08:10:32: dot1x-sm(Fa0/1): 0x8500004E:auth_bend_idle_request_action
called
004265: 08:10:32: dot1x-ev(Fa0/1): Role determination not required
004266: 08:10:32: dot1x-packet(Fa0/1): queuing an EAPOL pkt on Auth Q
004267: 08:10:32: dot1x-ev:Enqueued the eapol packet to the global
authenticator queue
004268: 08:10:32: EAPOL pak dump rx
004269: 08:10:32: EAPOL Version: 0x1 type: 0x1 length: 0x0000
004270: 08:10:32: dot1x-ev:
dot1x_auth_queue_event: Int Fa0/1 CODE= 0,TYPE= 0,LEN= 0
004271: 08:10:32: dot1x-packet(Fa0/1): Received an EAPOL frame
004272: 08:10:32: dot1x-ev(Fa0/1): Received pkt saddr =782b.cbd2.b26e ,
daddr = 0180.c200.0003, pae-ether-type = 888e.0101.0000
004273: 08:10:32: dot1x-packet(Fa0/1): Received an EAPOL-Start packet
004274: 08:10:32: EAPOL pak dump rx
004275: 08:10:32: EAPOL Version: 0x1 type: 0x1 length: 0x0000
004276: 08:10:32: dot1x-sm(Fa0/1): Posting EAPOL_START on Client 0x8500004E
004277: 08:10:32: dot1x_auth Fa0/1: during state auth_authenticating,
got event 4(eapolStart)
004278: 08:10:32: @@@ dot1x_auth Fa0/1: auth_authenticating -> auth_aborting
004279: 08:10:32: dot1x-sm(Fa0/1): 0x8500004E:auth_authenticating_exit
called
004280: 08:10:32: dot1x-sm(Fa0/1): 0x8500004E:auth_aborting_enter called
004281: 08:10:32: dot1x-sm(Fa0/1): Posting AUTH_ABORT for 0x8500004E
004282: 08:10:32: dot1x_auth_bend Fa0/1: during state
auth_bend_request, got event 1(authAbort)
004283: 08:10:32: @@@ dot1x_auth_bend Fa0/1: auth_bend_request ->
auth_bend_initialize
004284: 08:10:32: dot1x-sm(Fa0/1): 0x8500004E:auth_bend_initialize_enter
called
004285: 08:10:32: dot1x_auth_bend Fa0/1: idle during state
auth_bend_initialize
004286: 08:10:32: @@@ dot1x_auth_bend Fa0/1: auth_bend_initialize ->
auth_bend_idle
004287: 08:10:32: dot1x-sm(Fa0/1): 0x8500004E:auth_bend_idle_enter called
004288: 08:10:32: dot1x-sm(Fa0/1): Posting !AUTH_ABORT on Client 0x8500004E
004289: 08:10:32: dot1x_auth Fa0/1: during state auth_aborting, got
event 20(no_eapolLogoff_no_authAbort)
004290: 08:10:32: @@@ dot1x_auth Fa0/1: auth_aborting -> auth_restart
004291: 08:10:32: dot1x-sm(Fa0/1): 0x8500004E:auth_aborting_exit called
004292: 08:10:32: dot1x-sm(Fa0/1): 0x8500004E:auth_restart_enter called
004293: 08:10:32: dot1x-ev(Fa0/1): Resetting the client 0x8500004E
(782b.cbd2.b26e)
004294: 08:10:32: dot1x-ev(Fa0/1): Sending create new context event to EAP
for 0x8500004E (782b.cbd2.b26e)
004295: 08:10:32: dot1x-sm(Fa0/1): 0x8500004E:auth_aborting_restart_action
called
004296: 08:10:32: dot1x-sm(Fa0/1): Posting !EAP_RESTART on Client 0x8500004E
004297: 08:10:32: dot1x_auth Fa0/1: during state auth_restart, got
event 6(no_eapRestart)
004298: 08:10:32: @@@ dot1x_auth Fa0/1: auth_restart -> auth_connecting
004299: 08:10:32: dot1x-sm(Fa0/1): 0x8500004E:auth_connecting_enter called
004300: 08:10:32: dot1x-sm(Fa0/1):
0x8500004E:auth_restart_connecting_action called
004301: 08:10:32: dot1x-sm(Fa0/1): Posting RX_REQ on Client 0x8500004E
004302: 08:10:32: dot1x_auth Fa0/1: during state auth_connecting, got
event 10(eapReq_no_reAuthMax)
004303: 08:10:32: @@@ dot1x_auth Fa0/1: auth_connecting ->
auth_authenticating
004304: 08:10:32: dot1x-sm(Fa0/1): 0x8500004E:auth_authenticating_enter
called
004305: 08:10:32: dot1x-sm(Fa0/1):
0x8500004E:auth_connecting_authenticating_action called
004306: 08:10:32: dot1x-sm(Fa0/1): Posting AUTH_START for 0x8500004E
004307: 08:10:32: dot1x_auth_bend Fa0/1: during state auth_bend_idle,
got event 4(eapReq_authStart)
004308: 08:10:32: @@@ dot1x_auth_bend Fa0/1: auth_bend_idle ->
auth_bend_request
004309: 08:10:32: dot1x-sm(Fa0/1): 0x8500004E:auth_bend_request_enter called
004310: 08:10:32: dot1x-ev(Fa0/1): Sending EAPOL packet to 782b.cbd2.b26e
004311: 08:10:32: dot1x-ev(Fa0/1): Role determination not required
004312: 08:10:32: dot1x-registry:registry:dot1x_ether_macaddr called
004313: 08:10:32: dot1x-ev(Fa0/1): Sending out EAPOL packet
004314: 08:10:32: EAPOL pak dump Tx
004315: 08:10:32: EAPOL Version: 0x3 type: 0x0 length: 0x0005
004316: 08:10:32: EAP code: 0x1 id: 0x1 length: 0x0005 type: 0x1
004317: 08:10:32: dot1x-packet(Fa0/1): EAPOL packet sent to client
0x8500004E (782b.cbd2.b26e)
004318: 08:10:32: dot1x-sm(Fa0/1): 0x8500004E:auth_bend_idle_request_action
called
004319: *Mar 1 08:10:33: %LINK-3-UPDOWN: Interface FastEthernet0/1,
changed state to up
004320: *Mar 1 08:10:34: %LINEPROTO-5-UPDOWN: Line protocol on Interface
FastEthernet0/1, changed state to up
004321: 08:10:35: dot1x-sm(Fa0/1): Posting EAP_REQ for 0x8500004E
004322: 08:10:35: dot1x_auth_bend Fa0/1: during state
auth_bend_request, got event 7(eapReq)
004323: 08:10:35: @@@ dot1x_auth_bend Fa0/1: auth_bend_request ->
auth_bend_request
004324: 08:10:35: dot1x-sm(Fa0/1):
0x8500004E:auth_bend_request_request_action called
004325: 08:10:35: dot1x-sm(Fa0/1): 0x8500004E:auth_bend_request_enter called
004326: 08:10:35: dot1x-ev(Fa0/1): Sending EAPOL packet to 782b.cbd2.b26e
004327: 08:10:35: dot1x-ev(Fa0/1): Role determination not required
004328: 08:10:35: dot1x-registry:registry:dot1x_ether_macaddr called
004329: 08:10:35: dot1x-ev(Fa0/1): Sending out EAPOL packet
004330: 08:10:35: EAPOL pak dump Tx
004331: 08:10:35: EAPOL Version: 0x3 type: 0x0 length: 0x0005
004332: 08:10:35: EAP code: 0x1 id: 0x1 length: 0x0005 type: 0x1
004333: 08:10:35: dot1x-packet(Fa0/1): EAPOL packet sent to client
0x8500004E (782b.cbd2.b26e)
004334: 08:10:37: dot1x-ev(Fa0/1): Role determination not required
004335: 08:10:37: dot1x-packet(Fa0/1): queuing an EAPOL pkt on Auth Q
004336: 08:10:37: dot1x-ev:Enqueued the eapol packet to the global
authenticator queue
004337: 08:10:37: EAPOL pak dump rx
004338: 08:10:37: EAPOL Version: 0x1 type: 0x1 length: 0x0000
004339: 08:10:37: dot1x-ev:
dot1x_auth_queue_event: Int Fa0/1 CODE= 0,TYPE= 0,LEN= 0
004340: 08:10:37: dot1x-packet(Fa0/1): Received an EAPOL frame
004341: 08:10:37: dot1x-ev(Fa0/1): Received pkt saddr =782b.cbd2.b26e ,
daddr = 0180.c200.0003, pae-ether-type = 888e.0101.0000
004342: 08:10:37: dot1x-packet(Fa0/1): Received an EAPOL-Start packet
004343: 08:10:37: EAPOL pak dump rx
004344: 08:10:37: EAPOL Version: 0x1 type: 0x1 length: 0x0000
004345: 08:10:37: dot1x-sm(Fa0/1): Posting EAPOL_START on Client 0x8500004E
004346: 08:10:37: dot1x_auth Fa0/1: during state auth_authenticating,
got event 4(eapolStart)
004347: 08:10:37: @@@ dot1x_auth Fa0/1: auth_authenticating -> auth_aborting
004348: 08:10:37: dot1x-sm(Fa0/1): 0x8500004E:auth_authenticating_exit
called
004349: 08:10:37: dot1x-sm(Fa0/1): 0x8500004E:auth_aborting_enter called
004350: 08:10:37: dot1x-sm(Fa0/1): Posting AUTH_ABORT for 0x8500004E
004351: 08:10:37: dot1x_auth_bend Fa0/1: during state
auth_bend_request, got event 1(authAbort)
004352: 08:10:37: @@@ dot1x_auth_bend Fa0/1: auth_bend_request ->
auth_bend_initialize
004353: 08:10:37: dot1x-sm(Fa0/1): 0x8500004E:auth_bend_initialize_enter
called
004354: 08:10:37: dot1x_auth_bend Fa0/1: idle during state
auth_bend_initialize
004355: 08:10:37: @@@ dot1x_auth_bend Fa0/1: auth_bend_initialize ->
auth_bend_idle
004356: 08:10:37: dot1x-sm(Fa0/1): 0x8500004E:auth_bend_idle_enter called
004357: 08:10:37: dot1x-sm(Fa0/1): Posting !AUTH_ABORT on Client 0x8500004E
004358: 08:10:37: dot1x_auth Fa0/1: during state auth_aborting, got
event 20(no_eapolLogoff_no_authAbort)
004359: 08:10:37: @@@ dot1x_auth Fa0/1: auth_aborting -> auth_restart
004360: 08:10:37: dot1x-sm(Fa0/1): 0x8500004E:auth_aborting_exit called
004361: 08:10:37: dot1x-sm(Fa0/1): 0x8500004E:auth_restart_enter called
004362: 08:10:37: dot1x-ev(Fa0/1): Resetting the client 0x8500004E
(782b.cbd2.b26e)
004363: 08:10:37: dot1x-ev(Fa0/1): Sending create new context event to EAP
for 0x8500004E (782b.cbd2.b26e)
004364: 08:10:37: dot1x-sm(Fa0/1): 0x8500004E:auth_aborting_restart_action
called
004365: 08:10:37: dot1x-sm(Fa0/1): Posting !EAP_RESTART on Client 0x8500004E
004366: 08:10:37: dot1x_auth Fa0/1: during state auth_restart, got
event 6(no_eapRestart)
004367: 08:10:37: @@@ dot1x_auth Fa0/1: auth_restart -> auth_connecting
004368: 08:10:37: dot1x-sm(Fa0/1): 0x8500004E:auth_connecting_enter called
004369: 08:10:37: dot1x-sm(Fa0/1):
0x8500004E:auth_restart_connecting_action called
004370: 08:10:37: dot1x-sm(Fa0/1): Posting REAUTH_MAX on Client 0x8500004E
004371: 08:10:37: dot1x_auth Fa0/1: during state auth_connecting, got
event 11(reAuthMax)
004372: 08:10:37: @@@ dot1x_auth Fa0/1: auth_connecting -> auth_disconnected
004373: 08:10:37: dot1x-sm(Fa0/1): 0x8500004E:auth_disconnected_enter called
004374: 08:10:37: dot1x-sm(Fa0/1): 782b.cbd2.b26e:auth_disconnected_enter
sending canned failure to version 1 supplicant
004375: 08:10:37: dot1x-ev(Fa0/1): Sending EAPOL packet to 782b.cbd2.b26e
004376: 08:10:37: dot1x-ev(Fa0/1): Role determination not required
004377: 08:10:37: dot1x-registry:registry:dot1x_ether_macaddr called
004378: 08:10:37: dot1x-ev(Fa0/1): Sending out EAPOL packet
004379: 08:10:37: EAPOL pak dump Tx
004380: 08:10:37: EAPOL Version: 0x3 type: 0x0 length: 0x0004
004381: 08:10:37: EAP code: 0x4 id: 0x1 length: 0x0004
004382: 08:10:37: dot1x-packet(Fa0/1): dot1x_auth_txCannedStatus: EAPOL
packet sent to client 0x8500004E (782b.cbd2.b26e)
004383: 08:10:37: dot1x-sm(Fa0/1):
0x8500004E:auth_connecting_disconnected_reAuthMax_action called
004384: 08:10:37: dot1x_auth Fa0/1: idle during state auth_disconnected
004385: 08:10:37: @@@ dot1x_auth Fa0/1: auth_disconnected -> auth_restart
004386: 08:10:37: dot1x-ev(Fa0/1): Sending event (1) to Auth Mgr for
782b.cbd2.b26e
004387: 08:10:37: dot1x-ev:Delete auth client (0x8500004E) message
004388: 08:10:37: dot1x-ev:Auth client ctx destroyed
004389: 08:10:38: AAA/BIND(000001BE): Bind i/f
004390: 08:10:38: dot1x_auth Fa0/1: initial state auth_initialize has
enter
004391: 08:10:38: dot1x-sm(Fa0/1): 0xC000004F:auth_initialize_enter called
004392: 08:10:38: dot1x_auth Fa0/1: during state auth_initialize, got
event 0(cfg_auto)
004393: 08:10:38: @@@ dot1x_auth Fa0/1: auth_initialize -> auth_disconnected
004394: 08:10:38: dot1x-sm(Fa0/1): 0xC000004F:auth_disconnected_enter called
004395: 08:10:38: dot1x_auth Fa0/1: idle during state auth_disconnected
004396: 08:10:38: @@@ dot1x_auth Fa0/1: auth_disconnected -> auth_restart
004397: 08:10:38: dot1x-sm(Fa0/1): 0xC000004F:auth_restart_enter called
004398: 08:10:38: dot1x-ev(Fa0/1): Sending create new context event to EAP
for 0xC000004F (0000.0000.0000)
004399: 08:10:38: dot1x_auth_bend Fa0/1: initial state
auth_bend_initialize has enter
004400: 08:10:38: dot1x-sm(Fa0/1): 0xC000004F:auth_bend_initialize_enter
called
004401: 08:10:38: dot1x_auth_bend Fa0/1: initial state
auth_bend_initialize has idle
004402: 08:10:38: dot1x_auth_bend Fa0/1: during state
auth_bend_initialize, got event 16383(idle)
004403: 08:10:38: @@@ dot1x_auth_bend Fa0/1: auth_bend_initialize ->
auth_bend_idle
004404: 08:10:38: dot1x-sm(Fa0/1): 0xC000004F:auth_bend_idle_enter called
004405: 08:10:38: dot1x-ev(Fa0/1): Created a client entry (0xC000004F)
004406: 08:10:38: dot1x-ev(Fa0/1): Dot1x authentication started for
0xC000004F (0000.0000.0000)
004407: 08:10:38: dot1x-sm(Fa0/1): Posting !EAP_RESTART on Client 0xC000004F
004408: 08:10:38: dot1x_auth Fa0/1: during state auth_restart, got
event 6(no_eapRestart)
004409: 08:10:38: @@@ dot1x_auth Fa0/1: auth_restart -> auth_connecting
004410: 08:10:38: dot1x-sm(Fa0/1): 0xC000004F:auth_connecting_enter called
004411: 08:10:38: dot1x-sm(Fa0/1):
0xC000004F:auth_restart_connecting_action called
004412: 08:10:38: dot1x-sm(Fa0/1): Posting RX_REQ on Client 0xC000004F
004413: 08:10:38: dot1x_auth Fa0/1: during state auth_connecting, got
event 10(eapReq_no_reAuthMax)
004414: 08:10:38: @@@ dot1x_auth Fa0/1: auth_connecting ->
auth_authenticating
004415: 08:10:38: dot1x-sm(Fa0/1): 0xC000004F:auth_authenticating_enter
called
004416: 08:10:38: dot1x-sm(Fa0/1):
0xC000004F:auth_connecting_authenticating_action called
004417: 08:10:38: dot1x-sm(Fa0/1): Posting AUTH_START for 0xC000004F
004418: 08:10:38: dot1x_auth_bend Fa0/1: during state auth_bend_idle,
got event 4(eapReq_authStart)
004419: 08:10:38: @@@ dot1x_auth_bend Fa0/1: auth_bend_idle ->
auth_bend_request
004420: 08:10:38: dot1x-sm(Fa0/1): 0xC000004F:auth_bend_request_enter called
004421: 08:10:38: dot1x-ev(Fa0/1): Sending EAPOL packet to group PAE address
004422: 08:10:38: dot1x-ev(Fa0/1): Role determination not required
004423: 08:10:38: dot1x-registry:registry:dot1x_ether_macaddr called
004424: 08:10:38: dot1x-ev(Fa0/1): Sending out EAPOL packet
004425: 08:10:38: EAPOL pak dump Tx
004426: 08:10:38: EAPOL Version: 0x3 type: 0x0 length: 0x0005
004427: 08:10:38: EAP code: 0x1 id: 0x1 length: 0x0005 type: 0x1
004428: 08:10:38: dot1x-packet(Fa0/1): EAPOL packet sent to client
0xC000004F (0000.0000.0000)
004429: 08:10:38: dot1x-sm(Fa0/1): 0xC000004F:auth_bend_idle_request_action
called
004430: 08:10:39: dot1x-ev(Fa0/1): New client notification from AuthMgr for
0xC000004F - 782b.cbd2.b26e
004431: *Mar 1 08:10:39: %AUTHMGR-5-START: Starting 'dot1x' for client
(782b.cbd2.b26e) on Interface Fa0/1 AuditSessionID C0A864020000005D01C130A4
004432: 08:10:39: dot1x-sm(Fa0/1): Posting RESTART on Client 0xC000004F
004433: 08:10:39: dot1x_auth Fa0/1: during state auth_authenticating,
got event 13(restart)
004434: 08:10:39: @@@ dot1x_auth Fa0/1: auth_authenticating -> auth_aborting
004435: 08:10:39: dot1x-sm(Fa0/1): 0xC000004F:auth_authenticating_exit
called
004436: 08:10:39: dot1x-sm(Fa0/1): 0xC000004F:auth_aborting_enter called
004437: 08:10:39: dot1x-sm(Fa0/1):
0xC000004F:auth_authenticating_aborting_action called
004438: 08:10:39: dot1x-sm(Fa0/1): Posting AUTH_ABORT for 0xC000004F
004439: 08:10:39: dot1x_auth_bend Fa0/1: during state
auth_bend_request, got event 1(authAbort)
004440: 08:10:39: @@@ dot1x_auth_bend Fa0/1: auth_bend_request ->
auth_bend_initialize
004441: 08:10:39: dot1x-sm(Fa0/1): 0xC000004F:auth_bend_initialize_enter
called
004442: 08:10:39: dot1x_auth_bend Fa0/1: idle during state
auth_bend_initialize
004443: 08:10:39: @@@ dot1x_auth_bend Fa0/1: auth_bend_initialize ->
auth_bend_idle
004444: 08:10:39: dot1x-sm(Fa0/1): 0xC000004F:auth_bend_idle_enter called
004445: 08:10:39: dot1x-sm(Fa0/1): Posting !AUTH_ABORT on Client 0xC000004F
004446: 08:10:39: dot1x_auth Fa0/1: during state auth_aborting, got
event 20(no_eapolLogoff_no_authAbort)
004447: 08:10:39: @@@ dot1x_auth Fa0/1: auth_aborting -> auth_restart
004448: 08:10:39: dot1x-sm(Fa0/1): 0xC000004F:auth_aborting_exit called
004449: 08:10:39: dot1x-sm(Fa0/1): 0xC000004F:auth_restart_enter called
004450: 08:10:39: dot1x-ev(Fa0/1): Resetting the client 0xC000004F
(782b.cbd2.b26e)
004451: 08:10:39: dot1x-ev(Fa0/1): Sending create new context event to EAP
for 0xC000004F (782b.cbd2.b26e)
004452: 08:10:39: dot1x-sm(Fa0/1): 0xC000004F:auth_aborting_restart_action
called
004453: 08:10:39: dot1x-sm(Fa0/1): Posting !EAP_RESTART on Client 0xC000004F
004454: 08:10:39: dot1x_auth Fa0/1: during state auth_restart, got
event 6(no_eapRestart)
004455: 08:10:39: @@@ dot1x_auth Fa0/1: auth_restart -> auth_connecting
004456: 08:10:39: dot1x-sm(Fa0/1): 0xC000004F:auth_connecting_enter called
004457: 08:10:39: dot1x-sm(Fa0/1):
0xC000004F:auth_restart_connecting_action called
004458: 08:10:39: dot1x-sm(Fa0/1): Posting RX_REQ on Client 0xC000004F
004459: 08:10:39: dot1x_auth Fa0/1: during state auth_connecting, got
event 10(eapReq_no_reAuthMax)
004460: 08:10:39: @@@ dot1x_auth Fa0/1: auth_connecting ->
auth_authenticating
004461: 08:10:39: dot1x-sm(Fa0/1): 0xC000004F:auth_authenticating_enter
called
004462: 08:10:39: dot1x-sm(Fa0/1):
0xC000004F:auth_connecting_authenticating_action called
004463: 08:10:39: dot1x-sm(Fa0/1): Posting AUTH_START for 0xC000004F
004464: 08:10:39: dot1x_auth_bend Fa0/1: during state auth_bend_idle,
got event 4(eapReq_authStart)
004465: 08:10:39: @@@ dot1x_auth_bend Fa0/1: auth_bend_idle ->
auth_bend_request
004466: 08:10:39: dot1x-sm(Fa0/1): 0xC000004F:auth_bend_request_enter called
004467: 08:10:39: dot1x-ev(Fa0/1): Sending EAPOL packet to 782b.cbd2.b26e
004468: 08:10:39: dot1x-ev(Fa0/1): Role determination not required
004469: 08:10:39: dot1x-registry:registry:dot1x_ether_macaddr called
004470: 08:10:39: dot1x-ev(Fa0/1): Sending out EAPOL packet
004471: 08:10:39: EAPOL pak dump Tx
004472: 08:10:39: EAPOL Version: 0x3 type: 0x0 length: 0x0005
004473: 08:10:39: EAP code: 0x1 id: 0x1 length: 0x0005 type: 0x1
004474: 08:10:39: dot1x-packet(Fa0/1): EAPOL packet sent to client
0xC000004F (782b.cbd2.b26e)
004475: 08:10:39: dot1x-sm(Fa0/1): 0xC000004F:auth_bend_idle_request_action
called
004476: 08:10:42: dot1x-sm(Fa0/1): Posting EAP_REQ for 0xC000004F
004477: 08:10:42: dot1x_auth_bend Fa0/1: during state
auth_bend_request, got event 7(eapReq)
004478: 08:10:42: @@@ dot1x_auth_bend Fa0/1: auth_bend_request ->
auth_bend_request
004479: 08:10:42: dot1x-sm(Fa0/1):
0xC000004F:auth_bend_request_request_action called
004480: 08:10:42: dot1x-sm(Fa0/1): 0xC000004F:auth_bend_request_enter called
004481: 08:10:42: dot1x-ev(Fa0/1): Sending EAPOL packet to 782b.cbd2.b26e
004482: 08:10:42: dot1x-ev(Fa0/1): Role determination not required
004483: 08:10:42: dot1x-registry:registry:dot1x_ether_macaddr called
004484: 08:10:42: dot1x-ev(Fa0/1): Sending out EAPOL packet
004485: 08:10:42: EAPOL pak dump Tx
004486: 08:10:42: EAPOL Version: 0x3 type: 0x0 length: 0x0005
004487: 08:10:42: EAP code: 0x1 id: 0x1 length: 0x0005 type: 0x1
004488: 08:10:42: dot1x-packet(Fa0/1): EAPOL packet sent to client
0xC000004F (782b.cbd2.b26e)
004489: 08:10:42: dot1x-ev(Fa0/1): Role determination not required
004490: 08:10:42: dot1x-packet(Fa0/1): queuing an EAPOL pkt on Auth Q
004491: 08:10:42: dot1x-ev:Enqueued the eapol packet to the global
authenticator queue
004492: 08:10:42: EAPOL pak dump rx
004493: 08:10:42: EAPOL Version: 0x1 type: 0x1 length: 0x0000
004494: 08:10:42: dot1x-ev:
dot1x_auth_queue_event: Int Fa0/1 CODE= 0,TYPE= 0,LEN= 0
004495: 08:10:42: dot1x-packet(Fa0/1): Received an EAPOL frame
004496: 08:10:42: dot1x-ev(Fa0/1): Received pkt saddr =782b.cbd2.b26e ,
daddr = 0180.c200.0003, pae-ether-type = 888e.0101.0000
004497: 08:10:42: dot1x-packet(Fa0/1): Received an EAPOL-Start packet
004498: 08:10:42: EAPOL pak dump rx
004499: 08:10:42: EAPOL Version: 0x1 type: 0x1 length: 0x0000
004500: 08:10:42: dot1x-sm(Fa0/1): Posting EAPOL_START on Client 0xC000004F
004501: 08:10:42: dot1x_auth Fa0/1: during state auth_authenticating,
got event 4(eapolStart)
004502: 08:10:42: @@@ dot1x_auth Fa0/1: auth_authenticating -> auth_aborting
004503: 08:10:42: dot1x-sm(Fa0/1): 0xC000004F:auth_authenticating_exit
called
004504: 08:10:42: dot1x-sm(Fa0/1): 0xC000004F:auth_aborting_enter called
004505: 08:10:42: dot1x-sm(Fa0/1): Posting AUTH_ABORT for 0xC000004F
004506: 08:10:42: dot1x_auth_bend Fa0/1: during state
auth_bend_request, got event 1(authAbort)
004507: 08:10:42: @@@ dot1x_auth_bend Fa0/1: auth_bend_request ->
auth_bend_initialize
004508: 08:10:42: dot1x-sm(Fa0/1): 0xC000004F:auth_bend_initialize_enter
called
004509: 08:10:42: dot1x_auth_bend Fa0/1: idle during state
auth_bend_initialize
004510: 08:10:42: @@@ dot1x_auth_bend Fa0/1: auth_bend_initialize ->
auth_bend_idle
004511: 08:10:42: dot1x-sm(Fa0/1): 0xC000004F:auth_bend_idle_enter called
004512: 08:10:42: dot1x-sm(Fa0/1): Posting !AUTH_ABORT on Client 0xC000004F
004513: 08:10:42: dot1x_auth Fa0/1: during state auth_aborting, got
event 20(no_eapolLogoff_no_authAbort)
004514: 08:10:42: @@@ dot1x_auth Fa0/1: auth_aborting -> auth_restart
004515: 08:10:42: dot1x-sm(Fa0/1): 0xC000004F:auth_aborting_exit called
004516: 08:10:42: dot1x-sm(Fa0/1): 0xC000004F:auth_restart_enter called
004517: 08:10:42: dot1x-ev(Fa0/1): Resetting the client 0xC000004F
(782b.cbd2.b26e)
004518: 08:10:42: dot1x-ev(Fa0/1): Sending create new context event to EAP
for 0xC000004F (782b.cbd2.b26e)
004519: 08:10:42: dot1x-sm(Fa0/1): 0xC000004F:auth_aborting_restart_action
called
004520: 08:10:42: dot1x-sm(Fa0/1): Posting !EAP_RESTART on Client 0xC000004F
004521: 08:10:42: dot1x_auth Fa0/1: during state auth_restart, got
event 6(no_eapRestart)
004522: 08:10:42: @@@ dot1x_auth Fa0/1: auth_restart -> auth_connecting
004523: 08:10:42: dot1x-sm(Fa0/1): 0xC000004F:auth_connecting_enter called
004524: 08:10:42: dot1x-sm(Fa0/1):
0xC000004F:auth_restart_connecting_action called
004525: 08:10:42: dot1x-sm(Fa0/1): Posting RX_REQ on Client 0xC000004F
004526: 08:10:42: dot1x_auth Fa0/1: during state auth_connecting, got
event 10(eapReq_no_reAuthMax)
004527: 08:10:42: @@@ dot1x_auth Fa0/1: auth_connecting ->
auth_authenticating
004528: 08:10:42: dot1x-sm(Fa0/1): 0xC000004F:auth_authenticating_enter
called
004529: 08:10:42: dot1x-sm(Fa0/1):
0xC000004F:auth_connecting_authenticating_action called
004530: 08:10:42: dot1x-sm(Fa0/1): Posting AUTH_START for 0xC000004F
004531: 08:10:42: dot1x_auth_bend Fa0/1: during state auth_bend_idle,
got event 4(eapReq_authStart)
004532: 08:10:42: @@@ dot1x_auth_bend Fa0/1: auth_bend_idle ->
auth_bend_request
004533: 08:10:42: dot1x-sm(Fa0/1): 0xC000004F:auth_bend_request_enter called
004534: 08:10:42: dot1x-ev(Fa0/1): Sending EAPOL packet to 782b.cbd2.b26e
004535: 08:10:42: dot1x-ev(Fa0/1): Role determination not required
004536: 08:10:42: dot1x-registry:registry:dot1x_ether_macaddr called
004537: 08:10:42: dot1x-ev(Fa0/1): Sending out EAPOL packet
004538: 08:10:42: EAPOL pak dump Tx
004539: 08:10:42: EAPOL Version: 0x3 type: 0x0 length: 0x0005
004540: 08:10:42: EAP code: 0x1 id: 0x1 length: 0x0005 type: 0x1
004541: 08:10:42: dot1x-packet(Fa0/1): EAPOL packet sent to client
0xC000004F (782b.cbd2.b26e)
004542: 08:10:42: dot1x-sm(Fa0/1): 0xC000004F:auth_bend_idle_request_action
called
004543: 08:10:45: dot1x-sm(Fa0/1): Posting EAP_REQ for 0xC000004F
004544: 08:10:45: dot1x_auth_bend Fa0/1: during state
auth_bend_request, got event 7(eapReq)
004545: 08:10:45: @@@ dot1x_auth_bend Fa0/1: auth_bend_request ->
auth_bend_request
004546: 08:10:45: dot1x-sm(Fa0/1):
0xC000004F:auth_bend_request_request_action called
004547: 08:10:45: dot1x-sm(Fa0/1): 0xC000004F:auth_bend_request_enter called
004548: 08:10:45: dot1x-ev(Fa0/1): Sending EAPOL packet to 782b.cbd2.b26e
004549: 08:10:45: dot1x-ev(Fa0/1): Role determination not required
004550: 08:10:45: dot1x-registry:registry:dot1x_ether_macaddr called
004551: 08:10:45: dot1x-ev(Fa0/1): Sending out EAPOL packet
004552: 08:10:45: EAPOL pak dump Tx
004553: 08:10:45: EAPOL Version: 0x3 type: 0x0 length: 0x0005
004554: 08:10:45: EAP code: 0x1 id: 0x1 length: 0x0005 type: 0x1
004555: 08:10:45: dot1x-packet(Fa0/1): EAPOL packet sent to client
0xC000004F (782b.cbd2.b26e)
004556: 08:10:49: dot1x-sm(Fa0/1): Posting EAP_REQ for 0xC000004F
004557: 08:10:49: dot1x_auth_bend Fa0/1: during state
auth_bend_request, got event 7(eapReq)
004558: 08:10:49: @@@ dot1x_auth_bend Fa0/1: auth_bend_request ->
auth_bend_request
004559: 08:10:49: dot1x-sm(Fa0/1):
0xC000004F:auth_bend_request_request_action called
004560: 08:10:49: dot1x-sm(Fa0/1): 0xC000004F:auth_bend_request_enter called
004561: 08:10:49: dot1x-ev(Fa0/1): Sending EAPOL packet to 782b.cbd2.b26e
004562: 08:10:49: dot1x-ev(Fa0/1): Role determination not required
004563: 08:10:49: dot1x-registry:registry:dot1x_ether_macaddr called
004564: 08:10:49: dot1x-ev(Fa0/1): Sending out EAPOL packet
004565: 08:10:49: EAPOL pak dump Tx
004566: 08:10:49: EAPOL Version: 0x3 type: 0x0 length: 0x0005
004567: 08:10:49: EAP code: 0x1 id: 0x1 length: 0x0005 type: 0x1
004568: 08:10:49: dot1x-packet(Fa0/1): EAPOL packet sent to client
0xC000004F (782b.cbd2.b26e)
004569: 08:10:52: dot1x-ev(Fa0/1): Received an EAP Timeout
004570: 08:10:52: dot1x-sm(Fa0/1): Posting EAP_TIMEOUT for 0xC000004F
004571: 08:10:52: dot1x_auth_bend Fa0/1: during state
auth_bend_request, got event 12(eapTimeout)
004572: 08:10:52: @@@ dot1x_auth_bend Fa0/1: auth_bend_request ->
auth_bend_timeout
004573: 08:10:52: dot1x-sm(Fa0/1): 0xC000004F:auth_bend_timeout_enter called
004574: 08:10:52: dot1x-sm(Fa0/1):
0xC000004F:auth_bend_request_timeout_action called
004575: 08:10:52: dot1x_auth_bend Fa0/1: idle during state
auth_bend_timeout
004576: 08:10:52: @@@ dot1x_auth_bend Fa0/1: auth_bend_timeout ->
auth_bend_idle
004577: 08:10:52: dot1x-sm(Fa0/1): 0xC000004F:auth_bend_idle_enter called
004578: 08:10:52: dot1x-sm(Fa0/1): Posting AUTH_TIMEOUT on Client 0xC000004F
004579: 08:10:52: dot1x_auth Fa0/1: during state auth_authenticating,
got event 14(authTimeout)
004580: 08:10:52: @@@ dot1x_auth Fa0/1: auth_authenticating ->
auth_authc_result
004581: 08:10:52: dot1x-sm(Fa0/1): 0xC000004F:auth_authenticating_exit
called
004582: 08:10:52: dot1x-sm(Fa0/1): 0xC000004F:auth_authc_result_enter called
004583: *Mar 1 08:10:52: %DOT1X-5-FAIL: Authentication failed for client
(782b.cbd2.b26e) on Interface Fa0/1 AuditSessionID C0A864020000005D01C130A4
004584: 08:10:52: dot1x-ev(Fa0/1): Sending event (2) to Auth Mgr for
782b.cbd2.b26e
004585: *Mar 1 08:10:52: %AUTHMGR-7-RESULT: Authentication result
'timeout' from 'dot1x' for client (782b.cbd2.b26e) on Interface Fa0/1
AuditSessionID C0A864020000005D01C130A4
004586: 08:10:52: dot1x-ev(Fa0/1): Received Authz fail for the client
0xC000004F (782b.cbd2.b26e)
004587: 08:10:52: dot1x-sm(Fa0/1): Posting_AUTHZ_FAIL on Client 0xC000004F
004588: 08:10:52: dot1x_auth Fa0/1: during state auth_authc_result, got
event 22(authzFail)
004589: 08:10:52: @@@ dot1x_auth Fa0/1: auth_authc_result -> auth_held
004590: 08:10:52: dot1x-sm(Fa0/1): Posting RESTART on Client 0xC000004F
004591: 08:10:52: dot1x_auth Fa0/1: during state auth_held, got event
13(restart)
004592: 08:10:52: @@@ dot1x_auth Fa0/1: auth_held -> auth_restart
004593: 08:10:52: dot1x-sm(Fa0/1): 0xC000004F:auth_held_exit called
004594: 08:10:52: dot1x-sm(Fa0/1): 0xC000004F:auth_restart_enter called
004595: 08:10:52: dot1x-ev(Fa0/1): Resetting the client 0xC000004F
(782b.cbd2.b26e)
004596: 08:10:52: dot1x-ev(Fa0/1): Sending create new context event to EAP
for 0xC000004F (782b.cbd2.b26e)
004597: 08:10:52: dot1x-sm(Fa0/1): Posting !EAP_RESTART on Client 0xC000004F
004598: 08:10:52: dot1x_auth Fa0/1: during state auth_restart, got
event 6(no_eapRestart)
004599: 08:10:52: @@@ dot1x_auth Fa0/1: auth_restart -> auth_connecting
004600: 08:10:52: dot1x-sm(Fa0/1): 0xC000004F:auth_connecting_enter called
004601: 08:10:52: dot1x-sm(Fa0/1):
0xC000004F:auth_restart_connecting_action called
004602: 08:10:52: dot1x-sm(Fa0/1): Posting REAUTH_MAX on Client 0xC000004F
004603: 08:10:52: dot1x_auth Fa0/1: during state auth_connecting, got
event 11(reAuthMax)
004604: 08:10:52: @@@ dot1x_auth Fa0/1: auth_connecting -> auth_disconnected
004605: 08:10:52: dot1x-sm(Fa0/1): 0xC000004F:auth_disconnected_enter called
004606: 08:10:52: dot1x-sm(Fa0/1): 782b.cbd2.b26e:auth_disconnected_enter
sending canned failure to version 1 supplicant
004607: 08:10:52: dot1x-ev(Fa0/1): Sending EAPOL packet to 782b.cbd2.b26e
004608: 08:10:52: dot1x-ev(Fa0/1): Role determination not required
004609: 08:10:52: dot1x-registry:registry:dot1x_ether_macaddr called
004610: 08:10:52: dot1x-ev(Fa0/1): Sending out EAPOL packet
004611: 08:10:52: EAPOL pak dump Tx
004612: 08:10:52: EAPOL Version: 0x3 type: 0x0 length: 0x0004
004613: 08:10:52: EAP code: 0x4 id: 0x1 length: 0x0004
004614: 08:10:52: dot1x-packet(Fa0/1): dot1x_auth_txCannedStatus: EAPOL
packet sent to client 0xC000004F (782b.cbd2.b26e)
004615: 08:10:52: dot1x-sm(Fa0/1):
0xC000004F:auth_connecting_disconnected_reAuthMax_action called
004616: 08:10:52: dot1x_auth Fa0/1: idle during state auth_disconnected
004617: 08:10:52: @@@ dot1x_auth Fa0/1: auth_disconnected -> auth_restart
004618: 08:10:52: dot1x-ev(Fa0/1): Sending event (1) to Auth Mgr for
782b.cbd2.b26e
004619: 08:10:52: dot1x-ev:Delete auth client (0xC000004F) message
004620: 08:10:52: dot1x-ev:Auth client ctx destroyed
004621: 08:10:52: AAA/BIND(000001BF): Bind i/f
004622: 08:10:52: dot1x_auth Fa0/1: initial state auth_initialize has
enter
004623: 08:10:52: dot1x-sm(Fa0/1): 0xCB000050:auth_initialize_enter called
004624: 08:10:52: dot1x_auth Fa0/1: during state auth_initialize, got
event 0(cfg_auto)
004625: 08:10:52: @@@ dot1x_auth Fa0/1: auth_initialize -> auth_disconnected
004626: 08:10:52: dot1x-sm(Fa0/1): 0xCB000050:auth_disconnected_enter called
004627: 08:10:52: dot1x_auth Fa0/1: idle during state auth_disconnected
004628: 08:10:52: @@@ dot1x_auth Fa0/1: auth_disconnected -> auth_restart
004629: 08:10:52: dot1x-sm(Fa0/1): 0xCB000050:auth_restart_enter called
004630: 08:10:52: dot1x-ev(Fa0/1): Sending create new context event to EAP
for 0xCB000050 (0000.0000.0000)
004631: 08:10:52: dot1x_auth_bend Fa0/1: initial state
auth_bend_initialize has enter
004632: 08:10:52: dot1x-sm(Fa0/1): 0xCB000050:auth_bend_initialize_enter
called
004633: 08:10:52: dot1x_auth_bend Fa0/1: initial state
auth_bend_initialize has idle
004634: 08:10:52: dot1x_auth_bend Fa0/1: during state
auth_bend_initialize, got event 16383(idle)
004635: 08:10:52: @@@ dot1x_auth_bend Fa0/1: auth_bend_initialize ->
auth_bend_idle
004636: 08:10:52: dot1x-sm(Fa0/1): 0xCB000050:auth_bend_idle_enter called
004637: 08:10:52: dot1x-ev(Fa0/1): Created a client entry (0xCB000050)
004638: 08:10:52: dot1x-ev(Fa0/1): Dot1x authentication started for
0xCB000050 (0000.0000.0000)
004639: 08:10:52: dot1x-sm(Fa0/1): Posting !EAP_RESTART on Client 0xCB000050
004640: 08:10:52: dot1x_auth Fa0/1: during state auth_restart, got
event 6(no_eapRestart)
004641: 08:10:52: @@@ dot1x_auth Fa0/1: auth_restart -> auth_connecting
004642: 08:10:52: dot1x-sm(Fa0/1): 0xCB000050:auth_connecting_enter called
004643: 08:10:52: dot1x-sm(Fa0/1):
0xCB000050:auth_restart_connecting_action called
004644: 08:10:52: dot1x-sm(Fa0/1): Posting RX_REQ on Client 0xCB000050
004645: 08:10:52: dot1x_auth Fa0/1: during state auth_connecting, got
event 10(eapReq_no_reAuthMax)
004646: 08:10:52: @@@ dot1x_auth Fa0/1: auth_connecting ->
auth_authenticating
004647: 08:10:52: dot1x-sm(Fa0/1): 0xCB000050:auth_authenticating_enter
called
004648: 08:10:52: dot1x-sm(Fa0/1):
0xCB000050:auth_connecting_authenticating_action called
004649: 08:10:52: dot1x-sm(Fa0/1): Posting AUTH_START for 0xCB000050
004650: 08:10:52: dot1x_auth_bend Fa0/1: during state auth_bend_idle,
got event 4(eapReq_authStart)
004651: 08:10:52: @@@ dot1x_auth_bend Fa0/1: auth_bend_idle ->
auth_bend_request
004652: 08:10:52: dot1x-sm(Fa0/1): 0xCB000050:auth_bend_request_enter called
004653: 08:10:52: dot1x-ev(Fa0/1): Sending EAPOL packet to group PAE address
004654: 08:10:52: dot1x-ev(Fa0/1): Role determination not required
004655: 08:10:52: dot1x-registry:registry:dot1x_ether_macaddr called
004656: 08:10:52: dot1x-ev(Fa0/1): Sending out EAPOL packet
004657: 08:10:52: EAPOL pak dump Tx
004658: 08:10:52: EAPOL Version: 0x3 type: 0x0 length: 0x0005
004659: 08:10:52: EAP code: 0x1 id: 0x1 length: 0x0005 type: 0x1
004660: 08:10:52: dot1x-packet(Fa0/1): EAPOL packet sent to client
0xCB000050 (0000.0000.0000)
004661: 08:10:52: dot1x-sm(Fa0/1): 0xCB000050:auth_bend_idle_request_action
called
004662: 08:10:52: dot1x-ev(Fa0/1): New client notification from AuthMgr for
0xCB000050 - 782b.cbd2.b26e
004663: *Mar 1 08:10:52: %AUTHMGR-5-START: Starting 'dot1x' for client
(782b.cbd2.b26e) on Interface Fa0/1 AuditSessionID C0A864020000005E01C16861
004664: 08:10:52: dot1x-sm(Fa0/1): Posting RESTART on Client 0xCB000050
004665: 08:10:52: dot1x_auth Fa0/1: during state auth_authenticating,
got event 13(restart)
004666: 08:10:52: @@@ dot1x_auth Fa0/1: auth_authenticating -> auth_aborting
004667: 08:10:52: dot1x-sm(Fa0/1): 0xCB000050:auth_authenticating_exit
called
004668: 08:10:52: dot1x-sm(Fa0/1): 0xCB000050:auth_aborting_enter called
004669: 08:10:52: dot1x-sm(Fa0/1):
0xCB000050:auth_authenticating_aborting_action called
004670: 08:10:52: dot1x-sm(Fa0/1): Posting AUTH_ABORT for 0xCB000050
004671: 08:10:52: dot1x_auth_bend Fa0/1: during state
auth_bend_request, got event 1(authAbort)
004672: 08:10:52: @@@ dot1x_auth_bend Fa0/1: auth_bend_request ->
auth_bend_initialize
004673: 08:10:52: dot1x-sm(Fa0/1): 0xCB000050:auth_bend_initialize_enter
called
004674: 08:10:52: dot1x_auth_bend Fa0/1: idle during state
auth_bend_initialize
004675: 08:10:52: @@@ dot1x_auth_bend Fa0/1: auth_bend_initialize ->
auth_bend_idle
004676: 08:10:52: dot1x-sm(Fa0/1): 0xCB000050:auth_bend_idle_enter called
004677: 08:10:52: dot1x-sm(Fa0/1): Posting !AUTH_ABORT on Client 0xCB000050
004678: 08:10:52: dot1x_auth Fa0/1: during state auth_aborting, got
event 20(no_eapolLogoff_no_authAbort)
004679: 08:10:52: @@@ dot1x_auth Fa0/1: auth_aborting -> auth_restart
004680: 08:10:52: dot1x-sm(Fa0/1): 0xCB000050:auth_aborting_exit called
004681: 08:10:52: dot1x-sm(Fa0/1): 0xCB000050:auth_restart_enter called
004682: 08:10:52: dot1x-ev(Fa0/1): Resetting the client 0xCB000050
(782b.cbd2.b26e)
004683: 08:10:52: dot1x-ev(Fa0/1): Sending create new context event to EAP
for 0xCB000050 (782b.cbd2.b26e)
004684: 08:10:52: dot1x-sm(Fa0/1): 0xCB000050:auth_aborting_restart_action
called
004685: 08:10:52: dot1x-sm(Fa0/1): Posting !EAP_RESTART on Client 0xCB000050
004686: 08:10:52: dot1x_auth Fa0/1: during state auth_restart, got
event 6(no_eapRestart)
004687: 08:10:52: @@@ dot1x_auth Fa0/1: auth_restart -> auth_connecting
004688: 08:10:52: dot1x-sm(Fa0/1): 0xCB000050:auth_connecting_enter called
004689: 08:10:52: dot1x-sm(Fa0/1):
0xCB000050:auth_restart_connecting_action called
004690: 08:10:52: dot1x-sm(Fa0/1): Posting RX_REQ on Client 0xCB000050
004691: 08:10:52: dot1x_auth Fa0/1: during state auth_connecting, got
event 10(eapReq_no_reAuthMax)
004692: 08:10:52: @@@ dot1x_auth Fa0/1: auth_connecting ->
auth_authenticating
004693: 08:10:52: dot1x-sm(Fa0/1): 0xCB000050:auth_authenticating_enter
called
004694: 08:10:52: dot1x-sm(Fa0/1):
0xCB000050:auth_connecting_authenticating_action called
004695: 08:10:52: dot1x-sm(Fa0/1): Posting AUTH_START for 0xCB000050
004696: 08:10:52: dot1x_auth_bend Fa0/1: during state auth_bend_idle,
got event 4(eapReq_authStart)
004697: 08:10:52: @@@ dot1x_auth_bend Fa0/1: auth_bend_idle ->
auth_bend_request
004698: 08:10:52: dot1x-sm(Fa0/1): 0xCB000050:auth_bend_request_enter called
004699: 08:10:52: dot1x-ev(Fa0/1): Sending EAPOL packet to 782b.cbd2.b26e
004700: 08:10:52: dot1x-ev(Fa0/1): Role determination not required
004701: 08:10:52: dot1x-registry:registry:dot1x_ether_macaddr called
004702: 08:10:52: dot1x-ev(Fa0/1): Sending out EAPOL packet
004703: 08:10:52: EAPOL pak dump Tx
004704: 08:10:52: EAPOL Version: 0x3 type: 0x0 length: 0x0005
004705: 08:10:52: EAP code: 0x1 id: 0x1 length: 0x0005 type: 0x1
004706: 08:10:52: dot1x-packet(Fa0/1): EAPOL packet sent to client
0xCB000050 (782b.cbd2.b26e)
004707: 08:10:52: dot1x-sm(Fa0/1): 0xCB000050:auth_bend_idle_request_action
called
004708: 08:10:55: dot1x-sm(Fa0/1): Posting EAP_REQ for 0xCB000050
004709: 08:10:55: dot1x_auth_bend Fa0/1: during state
auth_bend_request, got event 7(eapReq)
004710: 08:10:55: @@@ dot1x_auth_bend Fa0/1: auth_bend_request ->
auth_bend_request
004711: 08:10:55: dot1x-sm(Fa0/1):
0xCB000050:auth_bend_request_request_action called
004712: 08:10:55: dot1x-sm(Fa0/1): 0xCB000050:auth_bend_request_enter called
004713: 08:10:55: dot1x-ev(Fa0/1): Sending EAPOL packet to 782b.cbd2.b26e
004714: 08:10:55: dot1x-ev(Fa0/1): Role determination not required
004715: 08:10:55: dot1x-registry:registry:dot1x_ether_macaddr called
004716: 08:10:55: dot1x-ev(Fa0/1): Sending out EAPOL packet
004717: 08:10:55: EAPOL pak dump Tx
004718: 08:10:55: EAPOL Version: 0x3 type: 0x0 length: 0x0005
004719: 08:10:55: EAP code: 0x1 id: 0x1 length: 0x0005 type: 0x1
004720: 08:10:55: dot1x-packet(Fa0/1): EAPOL packet sent to client
0xCB000050 (782b.cbd2.b26e)
004721: 08:10:58: dot1x-sm(Fa0/1): Posting EAP_REQ for 0xCB000050
004722: 08:10:58: dot1x_auth_bend Fa0/1: during state
auth_bend_request, got event 7(eapReq)
004723: 08:10:58: @@@ dot1x_auth_bend Fa0/1: auth_bend_request ->
auth_bend_request
004724: 08:10:58: dot1x-sm(Fa0/1):
0xCB000050:auth_bend_request_request_action called
004725: 08:10:58: dot1x-sm(Fa0/1): 0xCB000050:auth_bend_request_enter called
004726: 08:10:58: dot1x-ev(Fa0/1): Sending EAPOL packet to 782b.cbd2.b26e
004727: 08:10:58: dot1x-ev(Fa0/1): Role determination not required
004728: 08:10:58: dot1x-registry:registry:dot1x_ether_macaddr called
004729: 08:10:58: dot1x-ev(Fa0/1): Sending out EAPOL packet
004730: 08:10:58: EAPOL pak dump Tx
004731: 08:10:58: EAPOL Version: 0x3 type: 0x0 length: 0x0005
004732: 08:10:58: EAP code: 0x1 id: 0x1 length: 0x0005 type: 0x1
004733: 08:10:58: dot1x-packet(Fa0/1): EAPOL packet sent to client
0xCB000050 (782b.cbd2.b26e)
004734: 08:11:01: dot1x-ev(Fa0/1): Received an EAP Timeout
004735: 08:11:01: dot1x-sm(Fa0/1): Posting EAP_TIMEOUT for 0xCB000050
004736: 08:11:01: dot1x_auth_bend Fa0/1: during state
auth_bend_request, got event 12(eapTimeout)
004737: 08:11:01: @@@ dot1x_auth_bend Fa0/1: auth_bend_request ->
auth_bend_timeout
004738: 08:11:01: dot1x-sm(Fa0/1): 0xCB000050:auth_bend_timeout_enter called
004739: 08:11:01: dot1x-sm(Fa0/1):
0xCB000050:auth_bend_request_timeout_action called
004740: 08:11:01: dot1x_auth_bend Fa0/1: idle during state
auth_bend_timeout
004741: 08:11:01: @@@ dot1x_auth_bend Fa0/1: auth_bend_timeout ->
auth_bend_idle
004742: 08:11:01: dot1x-sm(Fa0/1): 0xCB000050:auth_bend_idle_enter called
004743: 08:11:01: dot1x-sm(Fa0/1): Posting AUTH_TIMEOUT on Client 0xCB000050
004744: 08:11:01: dot1x_auth Fa0/1: during state auth_authenticating,
got event 14(authTimeout)
004745: 08:11:01: @@@ dot1x_auth Fa0/1: auth_authenticating ->
auth_authc_result
004746: 08:11:01: dot1x-sm(Fa0/1): 0xCB000050:auth_authenticating_exit
called
004747: 08:11:01: dot1x-sm(Fa0/1): 0xCB000050:auth_authc_result_enter called
*004748: *Mar 1 08:11:01: %DOT1X-5-FAIL: Authentication failed for client
(782b.cbd2.b26e) on Interface Fa0/1 AuditSessionID C0A864020000005E01C16861*
004749: 08:11:01: dot1x-ev(Fa0/1): Sending event (2) to Auth Mgr for
782b.cbd2.b26e
*004750: *Mar 1 08:11:01: %AUTHMGR-7-RESULT: Authentication result
'no-response' from 'dot1x' for client (782b.cbd2.b26e) on Interface Fa0/1
AuditSessionID C0A864020000005E01C16861*
*004751: 08:11:01: dot1x-ev(Fa0/1): Received Authz fail for the client
0xCB000050 (782b.cbd2.b26e)*
004752: 08:11:01: dot1x-ev(Fa0/1): Deleting client 0xCB000050
(782b.cbd2.b26e)
*004753: *Mar 1 08:11:01: %AUTHMGR-7-FAILOVER: Failing over from 'dot1x'
for client (782b.cbd2.b26e) on Interface Fa0/1 AuditSessionID
C0A864020000005E01C16861*
*004754: *Mar 1 08:11:01: %AUTHMGR-5-START: Starting 'mab' for client
(782b.cbd2.b26e) on Interface Fa0/1 AuditSessionID C0A864020000005E01C16861*
004755: 08:11:01: dot1x-sm(Fa0/1): Posting_AUTHZ_FAIL on Client 0xCB000050
004756: 08:11:01: dot1x_auth Fa0/1: during state auth_authc_result, got
event 22(authzFail)
004757: 08:11:01: @@@ dot1x_auth Fa0/1: auth_authc_result -> auth_held
004758: 08:11:01: dot1x-ev:Delete auth client (0xCB000050) message
004759: 08:11:01: dot1x-ev:Auth client ctx destroyed
004760: 08:11:01: dot1x-ev:Aborted posting message to authenticator state
machine: Invalid client
004761: 08:11:01: AAA/AUTHEN/8021X (000001BF): Pick method list 'default'
004762: 08:11:02: SNMP: Packet received via UDP from 192.168.100.3 on Vlan1
004763: 08:11:02: SNMP: Get request, reqid 364044530, errstat 0, erridx 0
system.6.0 = NULL TYPE/VALUE
004764: 08:11:02:
Incoming SNMP packet
004765: 08:11:02: v2c packet
004766: 08:11:02: community string: ciscoRead
004767: 08:11:02: SNMP: Response, reqid 364044530, errstat 0, erridx 0
system.6.0 =
004768: 08:11:02: SNMP: Packet sent via UDP to 192.168.100.3
004769: *Mar 1 08:11:02: %MAB-5-SUCCESS: Authentication successful for
client (782b.cbd2.b26e) on Interface Fa0/1 AuditSessionID
C0A864020000005E01C16861
004770: *Mar 1 08:11:02: %AUTHMGR-7-RESULT: Authentication result
'success' from 'mab' for client (782b.cbd2.b26e) on Interface Fa0/1
AuditSessionID C0A864020000005E01C16861
*004771: *Mar 1 08:11:02: %AUTHMGR-5-VLANASSIGN: VLAN 2 assigned to
Interface Fa0/1 AuditSessionID C0A864020000005E01C16861*
*004772: *Mar 1 08:11:02: %AUTHMGR-5-FAIL: Authorization failed or
unapplied for client (782b.cbd2.b26e) on Interface Fa0/1 AuditSessionID
C0A864020000005E01C16861*
*004773: *Mar 1 08:11:04: %AUTHMGR-5-SUCCESS: Authorization succeeded for
client (782b.cbd2.b26e) on Interface Fa0/1 AuditSessionID
C0A864020000005E01C16861*
------------------------------------------------------------------------------
_______________________________________________
PacketFence-users mailing list
PacketFence-users@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/packetfence-users
