Solved: Tacacs on 3504WLC

zender42 · ‎07-16-2019

Hey everyone,

I seem to be having a strange issue with Tacacs+ on a 3504WLC. Authentication to this T+ server works fine on my other cisco devices, but for some reason, is giving me the '-6 Internal Error' remark. I havent been able to find any correlating information online such as more possible issues with what cause -6 or deciphering the AuthorizationResponse. Any help from the hivemind would be appreciated?

Thanks!

*tplusTransportThread: Jul 16 16:15:16.109: [PA] Process authentication response of len =144 from server 10.10.5.115
*tplusTransportThread: Jul 16 16:15:16.109: [PA] 00000000: c0 01 04 00 fd 63 27 7f  00 00 00 84 66 a9 5e 05  .....c'.....f.^.
*tplusTransportThread: Jul 16 16:15:16.109: [PA] 00000010: 2d 7f d9 f8 c7 7d 80 cc  0d ca 6b 09 56 03 a8 b0  -....}....k.V...
*tplusTransportThread: Jul 16 16:15:16.109: [PA] 00000020: 64 4c 9e 22 6e 97 7a c3  23 47 2d 14 d9 81 4d 9b  dL."n.z.#G-...M.
*tplusTransportThread: Jul 16 16:15:16.109: [PA] 00000030: 83 fd 82 cc d9 98 10 51  1e 9f 5b 82 31 15 20 6a  .......Q..[.1..j
*tplusTransportThread: Jul 16 16:15:16.109: [PA] 00000050: 15 a3 fa c1 40 2e e6 16  7f 74 e2 23 eb 3a 99 6d  ....@....t.#.:.m
*tplusTransportThread: Jul 16 16:15:16.109: [PA] 00000060: 38 05 b4 06 19 ff 33 e7  35 3d bc 2f 45 b2 0e 29  8.....3.5=./E..)
*tplusTransportThread: Jul 16 16:15:16.109: [PA] 00000070: 62 3d b5 9c 3d 9d 5b f8  f3 e9 4b a3 46 d3 5d a4  b=..=.[...K.F.].
*tplusTransportThread: Jul 16 16:15:16.109: [PA] 00000080: b0 54 2c b4 28 e9 cc 1e  a4 94 bb a1 d1 66 f8 c6  .T,.(........f..
*tplusTransportThread: Jul 16 16:15:16.109: [PA] Found matching request for tplus auth response (len 144): type=1 seq_no=4 session_id=fd63277f length=132 encrypted=0
*tplusTransportThread: Jul 16 16:15:16.109: [PA] TPLUS_AUTHEN_STATUS_GETDATA

*tplusTransportThread: Jul 16 16:15:16.109: [PA] 00:00:00:4c:00:00 Returning AAA Error 'Internal Error' (-6) for mobile 00:00:00:4c:00:00
*tplusTransportThread: Jul 16 16:15:16.109: [PA] AuthorizationResponse: 0xff41da9600


*tplusTransportThread: Jul 16 16:15:16.109: [PA]        structureSize................................128

*tplusTransportThread: Jul 16 16:15:16.109: [PA]        resultCode...................................-6

*tplusTransportThread: Jul 16 16:15:16.109: [PA]        protocolUsed.................................0xffffffff

*tplusTransportThread: Jul 16 16:15:16.109: [PA]        proxyState...................................00:00:00:4C:00:00-00:00

*tplusTransportThread: Jul 16 16:15:16.109: [PA]        Packet contains 0 AVPs:

*tplusTransportThread: Jul 16 16:15:16.110: [PA] tplusProcessIncomingMessages no POLLIN event on sockfd
*emWeb: Jul 16 16:15:16.110: [PA] Authentication failed for USERNAME

hslai · ‎07-20-2019

This is likely a configuration issue. Please check the following resources;

View solution in original post

hslai · ‎07-16-2019

If this is the only WLC you have, then most likely the response from ISE is not what it expected. If the same working for another WLC, then please check how they are differing (model or WLC code).

Sathiyanarayanan Ravindran · ‎07-16-2019

Hi @zender42 ,

Whats the priority order configured on the WLC, By default TACACS will be not included in the authentication priority order. Check the sequence once.

Post the output of debug aaa tacacs enable

Regards,
Sathiyanarayanan Ravindran

Please rate the post and accept as solution, if my response satisfied your question:)

zender42 · ‎07-17-2019

Before our wireless was all autonomous or on different platforms with uniformity. We have recently consolidated our wireless onto this WLC. Sorry for the confusion, by TACACs working other equipment, I meant switches, routers, etc The WLC is a new addition to our network

Here is the debug dump. For some reason this time, It is now posting as Auth Error -4. Yesterday it was -6.

Note: Any External IPs replaced with x.x.x.x

(Cisco Controller) >*emWeb: Jul 17 09:28:13.443: [PA] Authentication failed for USERNAME
*aaaQueueReader: Jul 17 09:28:24.242: [PA] Unable to find requested user entry for USERNAME
*aaaQueueReader: Jul 17 09:28:24.242: [PA] ReProcessAuthentication previous proto 28, next proto 20010
*aaaQueueReader: Jul 17 09:28:24.242: [PA] AuthenticationRequest: 0xffe96604f0


*aaaQueueReader: Jul 17 09:28:24.242: [PA]      Callback.....................................0x119091e8

*aaaQueueReader: Jul 17 09:28:24.242: [PA]      protocolType.................................0x00020010

*aaaQueueReader: Jul 17 09:28:24.242: [PA]      proxyState...................................00:00:00:51:00:00-00:00

*aaaQueueReader: Jul 17 09:28:24.242: [PA]      Packet contains 5 AVPs:

*aaaQueueReader: Jul 17 09:28:24.242: [PA]          AVP[01] User-Name................................USERNAME (9 bytes)

*aaaQueueReader: Jul 17 09:28:24.242: [PA]          AVP[02] User-Password............................[...]

*aaaQueueReader: Jul 17 09:28:24.242: [PA]          AVP[03] Service-Type.............................0x00000007 (7) (4 bytes)

*aaaQueueReader: Jul 17 09:28:24.242: [PA]          AVP[04] Nas-Ip-Address...........................0x0a5b05e6 (173737446) (4 bytes)

*aaaQueueReader: Jul 17 09:28:24.243: [PA]          AVP[05] NAS-Identifier...........................clwwlc1 (7 bytes)

*aaaQueueReader: Jul 17 09:28:24.243: [PA] 00:00:00:51:00:00 User entry not found in the Local FileDB for the client.
*tplusTransportThread: Jul 17 09:28:24.444: [PA] Selected Tplus server 10.10.5.115 (port:49, fd:0) to send the message
*tplusTransportThread: Jul 17 09:28:24.444: [PA] Setup the Tplus socket for server 10.10.5.115 (port:49)
*tplusTransportThread: Jul 17 09:28:24.444: [PA] Connecting to tacacs server 10.10.5.115 on port=49 on sockFd= 114
*tplusTransportThread: Jul 17 09:28:24.444: [PA] Tplus server (10.10.5.115) start polling for 5sec
*tplusTransportThread: Jul 17 09:28:24.444: [PA] Tplus server (10.10.5.115) connect success
*tplusTransportThread: Jul 17 09:28:24.444: [PA] Sent Tplus message on server 10.10.5.115 (port:49, sockFd=114),
*tplusTransportThread: Jul 17 09:28:24.444: [PA] Sent Auth msg (session_id:0, seq_no:1) on server: 10.10.5.115. Num Acct MsgInAuthQ: 1
*tplusTransportThread: Jul 17 09:28:24.444: [PA] populated pollIndex0 auth1 10.10.5.115(114)
*tplusTransportThread: Jul 17 09:28:24.446: [PA] poll0 auth1 10.10.5.115(114) processIncomingMsgs
*tplusTransportThread: Jul 17 09:28:24.446: [PA] Received Tacacs response from server 10.10.5.115 of len (28) hdrLen 16, seq_no=2 session_id=d7aae841
*tplusTransportThread: Jul 17 09:28:24.446: [PA] Process authentication response of len =28 from server 10.10.5.115
*tplusTransportThread: Jul 17 09:28:24.446: [PA] 00000000: c0 01 02 00 d7 aa e8 41  00 00 00 10 38 4d 4e 37  .......A....8MN7
*tplusTransportThread: Jul 17 09:28:24.446: [PA] 00000010: 00 df cd 80 6d 54 ea 1a  36 f2 b7 38              ....mT..6..8
*tplusTransportThread: Jul 17 09:28:24.447: [PA] Found matching request for tplus auth response (len 28): type=1 seq_no=2 session_id=d7aae841 length=16 encrypted=0
*tplusTransportThread: Jul 17 09:28:24.447: [PA] TPLUS_AUTHEN_STATUS_GETPASS

*tplusTransportThread: Jul 17 09:28:24.447: [PA] auth_cont get_pass reply: pkt_length=29

*tplusTransportThread: Jul 17 09:28:24.447: [PA] processTplusAuthResponse: Continue auth transaction
*tplusTransportThread: Jul 17 09:28:24.947: [PA] tplusProcessIncomingMessages poll timeout: 150:Operation now in progress
*tplusTransportThread: Jul 17 09:28:24.947: [PA] Selected Tplus server 10.10.5.115 (port:49, fd:114) to send the message
*tplusTransportThread: Jul 17 09:28:24.947: [PA] Sent the Tplus message on server 10.10.5.115 (port:49, sockFd=114)
*tplusTransportThread: Jul 17 09:28:24.947: [PA] Sent Auth msg (session_id:0, seq_no:1) on server: 10.10.5.115. Num Acct MsgInAuthQ: 1
*tplusTransportThread: Jul 17 09:28:24.947: [PA] populated pollIndex0 auth1 10.10.5.115(114)
*tplusTransportThread: Jul 17 09:28:26.033: [PA] poll0 auth1 10.10.5.115(114) processIncomingMsgs
*tplusTransportThread: Jul 17 09:28:26.033: [PA] Received Tacacs response from server 10.10.5.115 of len (18) hdrLen 6, seq_no=4 session_id=d7aae841
*tplusTransportThread: Jul 17 09:28:26.033: [PA] Process authentication response of len =18 from server 10.10.5.115
*tplusTransportThread: Jul 17 09:28:26.033: [PA] 00000000: c0 01 04 00 d7 aa e8 41  00 00 00 06 3e ed 87 c5  .......A....>...
*tplusTransportThread: Jul 17 09:28:26.033: [PA] 00000010: 1f 5d                                             .]
*tplusTransportThread: Jul 17 09:28:26.033: [PA] Found matching request for tplus auth response (len 18): type=1 seq_no=4 session_id=d7aae841 length=6 encrypted=0
*tplusTransportThread: Jul 17 09:28:26.033: [PA] 00:00:00:51:00:00 Returning AAA Error 'Authentication Failed' (-4) for mobile 00:00:00:51:00:00
*tplusTransportThread: Jul 17 09:28:26.033: [PA] AuthorizationResponse: 0xff41da9600


*tplusTransportThread: Jul 17 09:28:26.033: [PA]        structureSize................................128

*tplusTransportThread: Jul 17 09:28:26.033: [PA]        resultCode...................................-4

*tplusTransportThread: Jul 17 09:28:26.033: [PA]        protocolUsed.................................0xffffffff

*tplusTransportThread: Jul 17 09:28:26.033: [PA]        proxyState...................................00:00:00:51:00:00-00:00

*tplusTransportThread: Jul 17 09:28:26.033: [PA]        Packet contains 0 AVPs:

*tplusTransportThread: Jul 17 09:28:26.033: [PA] TPLUS_AUTHEN_STATUS_FAIL: username=[USERNAME]
*tplusTransportThread: Jul 17 09:28:26.033: [PA] tplusProcessIncomingMessages no POLLIN event on sockfd
*emWeb: Jul 17 09:28:26.033: [PA] Authentication failed for USERNAME

(Cisco Controller) >*Dot1x_NW_MsgTask_1: Jul 17 09:36:31.444: [PA] b4:f7:a1:c2:a1:09 Sending Accounting request (0) for station b4:f7:a1:c2:a1:09
*Dot1x_NW_MsgTask_1: Jul 17 09:36:31.444: [PA] b4:f7:a1:c2:a1:09 PemLocationConfigured [1]Adding VSA with NAS update and Role[1] with state[0]
*aaaQueueReader: Jul 17 09:36:31.444: [PA] AccountingMessage Accounting Interim: 0xffe669a7b8

*aaaQueueReader: Jul 17 09:36:31.444: [PA]      Packet contains 25 AVPs:

*aaaQueueReader: Jul 17 09:36:31.444: [PA]          AVP[01] User-Name................................b4-f7-a1-c2-a1-09 (17 bytes)

*aaaQueueReader: Jul 17 09:36:31.444: [PA]          AVP[02] Nas-Port.................................0x00000005 (5) (4 bytes)

*aaaQueueReader: Jul 17 09:36:31.444: [PA]          AVP[03] Nas-Ip-Address...........................0x0a5b05e6 (173737446) (4 bytes)

*aaaQueueReader: Jul 17 09:36:31.444: [PA]          AVP[04] Framed-IP-Address........................0xc0a86395 (-1062706283) (4 bytes)

*aaaQueueReader: Jul 17 09:36:31.444: [PA]          AVP[05] NAS-Identifier...........................clwwlc1 (7 bytes)

*aaaQueueReader: Jul 17 09:36:31.444: [PA]          AVP[06] Airespace / WLAN-Identifier..............0x00000006 (6) (4 bytes)

*aaaQueueReader: Jul 17 09:36:31.444: [PA]          AVP[07] Acct-Session-Id..........................5d2f1d72/b4:f7:a1:c2:a1:09/2479 (31 bytes)

*aaaQueueReader: Jul 17 09:36:31.444: [PA]          AVP[08] Nas-Port-Type............................0x00000013 (19) (4 bytes)

*aaaQueueReader: Jul 17 09:36:31.444: [PA]          AVP[09] Cisco / Audit-Session-Id.................0a5b05e6000009365d2f1d72 (24 bytes)

*aaaQueueReader: Jul 17 09:36:31.444: [PA]          AVP[10] Acct-Authentic...........................0x00000003 (3) (4 bytes)

*aaaQueueReader: Jul 17 09:36:31.444: [PA]          AVP[11] Tunnel-Type..............................0x0000000d (13) (4 bytes)

*aaaQueueReader: Jul 17 09:36:31.444: [PA]          AVP[12] Tunnel-Medium-Type.......................0x00000006 (6) (4 bytes)

*aaaQueueReader: Jul 17 09:36:31.444: [PA]          AVP[13] Tunnel-Group-Id..........................999 (3 bytes)

*aaaQueueReader: Jul 17 09:36:31.444: [PA]          AVP[14] Acct-Event-Time..........................0x5d2f245f (1563370591) (4 bytes)

*aaaQueueReader: Jul 17 09:36:31.444: [PA]          AVP[15] Acct-Status-Type.........................0x00000003 (3) (4 bytes)

*aaaQueueReader: Jul 17 09:36:31.444: [PA]          AVP[16] Acct-Input-Octets........................0x00197137 (1667383) (4 bytes)

*aaaQueueReader: Jul 17 09:36:31.444: [PA]          AVP[17] Acct-Input-GigaWords.....................0x00000000 (0) (4 bytes)

*aaaQueueReader: Jul 17 09:36:31.444: [PA]          AVP[18] Acct-Output-Octets.......................0x001ac3c6 (1754054) (4 bytes)

*aaaQueueReader: Jul 17 09:36:31.444: [PA]          AVP[19] Acct-Output-GigaWords....................0x00000000 (0) (4 bytes)

*aaaQueueReader: Jul 17 09:36:31.444: [PA]          AVP[20] Acct-Input-Packets.......................0x000011d4 (4564) (4 bytes)

*aaaQueueReader: Jul 17 09:36:31.444: [PA]          AVP[21] Acct-Output-Packets......................0x00000e10 (3600) (4 bytes)

*aaaQueueReader: Jul 17 09:36:31.444: [PA]          AVP[22] Acct-Session-Time........................0x000006ed (1773) (4 bytes)

*aaaQueueReader: Jul 17 09:36:31.444: [PA]          AVP[23] Acct-Delay-Time..........................0x00000000 (0) (4 bytes)

*aaaQueueReader: Jul 17 09:36:31.444: [PA]          AVP[24] Calling-Station-Id.......................b4-f7-a1-c2-a1-09 (17 bytes)

*aaaQueueReader: Jul 17 09:36:31.444: [PA]          AVP[25] Called-Station-Id........................cc-70-ed-15-df-f0 (17 bytes)

*aaaQueueReader: Jul 17 09:36:31.444: [PA] b4:f7:a1:c2:a1:09 radiusServerFallbackPassiveStateUpdate: RADIUS server is ready x.x.x.x port 1813 index 2 active 1
*aaaQueueReader: Jul 17 09:36:31.444: [PA] b4:f7:a1:c2:a1:09 radiusServerFallbackPassiveStateUpdate: RADIUS server is maybe-ready x.x.x.x port 1813 index 3 active 1
*aaaQueueReader: Jul 17 09:36:31.444: [PA] b4:f7:a1:c2:a1:09 NAI-Realm not enabled on Wlan, radius servers will be selected as usual
*aaaQueueReader: Jul 17 09:36:31.444: [PA] 00:00:00:06:00:00 Found the radius server : x.x.x.x from the global server list
*aaaQueueReader: Jul 17 09:36:31.444: [PA] b4:f7:a1:c2:a1:09 Send Radius Acct Request with pktId:28 into qid:9 of server at index:2
*aaaQueueReader: Jul 17 09:36:31.444: [PA] b4:f7:a1:c2:a1:09 Sending the packet to v4 host x.x.x.x:1813 of length 287
*aaaQueueReader: Jul 17 09:36:31.444: [PA] b4:f7:a1:c2:a1:09 Successful transmission of Accounting-Interim (pktId 28) to x.x.x.x:1813 from server queue 9, proxy state b4:f7:a1:c2:a1:09-00:00
*aaaQueueReader: Jul 17 09:36:31.444: [PA] 00000000: 04 1c 01 1f 33 0a 41 b8  4b 3c cb 4a 8a c9 7c 00  ....3.A.K<.J..|.
*aaaQueueReader: Jul 17 09:36:31.444: [PA] 00000010: 1c db f0 e2 01 13 62 34  2d 66 37 2d 61 31 2d 63  ......b4-f7-a1-c
*aaaQueueReader: Jul 17 09:36:31.444: [PA] 00000020: 32 2d 61 31 2d 30 39 05  06 00 00 00 05 04 06 0a  2-a1-09.........
*aaaQueueReader: Jul 17 09:36:31.444: [PA] 00000030: 5b 05 e6 08 06 c0 a8 63  95 20 09 63 6c 77 77 6c  [......c...clwwl
*aaaQueueReader: Jul 17 09:36:31.444: [PA] 00000040: 63 31 1a 0c 00 00 37 63  01 06 00 00 00 06 2c 21  c1....7c......,!
*aaaQueueReader: Jul 17 09:36:31.444: [PA] 00000050: 35 64 32 66 31 64 37 32  2f 62 34 3a 66 37 3a 61  5d2f1d72/b4:f7:a
*aaaQueueReader: Jul 17 09:36:31.444: [PA] 00000060: 31 3a 63 32 3a 61 31 3a  30 39 2f 32 34 37 39 3d  1:c2:a1:09/2479=
*aaaQueueReader: Jul 17 09:36:31.444: [PA] 00000070: 06 00 00 00 13 1a 31 00  00 00 09 01 2b 61 75 64  ......1.....+aud
*aaaQueueReader: Jul 17 09:36:31.444: [PA] 00000080: 69 74 2d 73 65 73 73 69  6f 6e 2d 69 64 3d 30 61  it-session-id=0a
*aaaQueueReader: Jul 17 09:36:31.444: [PA] 00000090: 35 62 30 35 65 36 30 30  30 30 30 39 33 36 35 64  5b05e6000009365d
*aaaQueueReader: Jul 17 09:36:31.444: [PA] 000000a0: 32 66 31 64 37 32 2d 06  00 00 00 03 40 06 00 00  2f1d72-.....@...
*aaaQueueReader: Jul 17 09:36:31.444: [PA] 000000b0: 00 0d 41 06 00 00 00 06  51 05 39 39 39 37 06 5d  ..A.....Q.9997.]
*aaaQueueReader: Jul 17 09:36:31.444: [PA] 000000c0: 2f 24 5f 28 06 00 00 00  03 2a 06 00 19 71 37 34  /$_(.....*...q74
*aaaQueueReader: Jul 17 09:36:31.444: [PA] 000000d0: 06 00 00 00 00 2b 06 00  1a c3 c6 35 06 00 00 00  .....+.....5....
*aaaQueueReader: Jul 17 09:36:31.444: [PA] 000000e0: 00 2f 06 00 00 11 d4 30  06 00 00 0e 10 2e 06 00  ./.....0........
*aaaQueueReader: Jul 17 09:36:31.444: [PA] 000000f0: 00 06 ed 29 06 00 00 00  00 1f 13 62 34 2d 66 37  ...).......b4-f7
*aaaQueueReader: Jul 17 09:36:31.444: [PA] 00000100: 2d 61 31 2d 63 32 2d 61  31 2d 30 39 1e 13 63 63  -a1-c2-a1-09..cc
*radiusTransportThread: Jul 17 09:36:31.490: [PA] b4:f7:a1:c2:a1:09 Counted 0 AVPs (processed 20 bytes, left 0)

hslai · ‎07-20-2019

This is likely a configuration issue. Please check the following resources;