Command Authorization Failed

[JDMJeffy84]

Hey guys,

Wonder if you guys can assist me in troubleshooting a Tacacs/ AAA issue.

Cisco ACS 5.3 server decided to blow up and corrupt itself on the weekend. However, I managed to build it up again with most of the configurations.
I'm having trouble getting pass privilege mode on the switches and routers.

I can authenticate using my Active directory account username and password fine but when I issue commands I get Command Authorization Failed:

Welcome any thoughts! 

** Tacacs was working before the server blew up! I suspect I've missed something on the ACS GUI setup**

Attached debug tacacs

=====================

username: 
Aug 26 12:39:14.142: TPLUS: Queuing AAA Authentication request 4950 for processing
Aug 26 12:39:14.142: TPLUS(00001356) login timer started 1020 sec timeout
Aug 26 12:39:14.142: TPLUS: processing authentication start request id 4950
Aug 26 12:39:14.143: TPLUS: Authentication start packet created for 4950()
Aug 26 12:39:14.143: TPLUS: Using server 192.168.x.x
Aug 26 12:39:14.148: TPLUS(00001356)/0/NB_WAIT/3A72C8D0: Started 5 sec timeout
Aug 26 12:39:14.150: TPLUS(00001356)/0/NB_WAIT: socket event
username:  2
Aug 26 12:39:14.151: TPLUS(00001356)/0/NB_WAIT: wrote entire 29 bytes request
Aug 26 12:39:14.151: TPLUS(00001356)/0/READ: socket event 1
Aug 26 12:39:14.151: TPLUS(00001356)/0/READ: Would block while reading
Aug 26 12:39:14.155: TPLUS(00001356)/0/READ: socket event 1
Aug 26 12:39:14.155: TPLUS(00001356)/0/READ: read entire 12 header bytes (expect 16 bytes data)
Aug 26 12:39:14.155: TPLUS(00001356)/0/READ: socket event 1
Aug 26 12:39:14.155: TPLUS(00001356)/0/READ: read entire 28 bytes response

username: Aug 26 12:39:14.155: TPLUS(00001356)/0/3A72C8D0: Processing the reply packet
Aug 26 12:39:14.155: TPLUS: Received authen response status GET_USER (7)
username: USER55
password: 
Aug 26 12:39:23.813: TPLUS: Queuing AAA Authentication request 4950 for processing
Aug 26 12:39:23.813: TPLUS(00001356) login timer started 1020 sec timeout
Aug 26 12:39:23.813: TPLUS: processing authentication continue request id 4950
Aug 26 12:39:23.813: TPLUS: Authentication continue packet generated for 4950
Aug 26 12:39:23.813: TPLUS(00001356)/0/WRITE/3A72C8D0: Started 5 sec timeout
Aug 26 12:39:23.814: TPLUS(00001356)/0/WRITE: wrote entire 28 bytes request
Aug 26 12:39:25.077: TPLUS(00001356)/0/READ: socket event 1
Aug 26 12:39:25.077: TPLUS(00001356)/0/READ: read entire 12 header bytes (expect 16 bytes data)
Aug 26 12:39:25.077: TPLUS(00001356)/0/READ: socket event 1
Aug 26 12:39:25.077: TPLUS(00001356)/0/READ: read entire 28 bytes response
Aug 26 12:39:25.077: TPLUS(00001356)/0/3A72C8D0: Processing the reply packet
Aug 26 12:39:25.077: TPLUS: Received authen response status GET_PASSWORD (8)

Aug 26 12:39:33.670: TPLUS: Queuing AAA Authentication request 4950 for processing
Aug 26 12:39:33.671: TPLUS(00001356) login timer started 1020 sec timeout
Aug 26 12:39:33.671: TPLUS: processing authentication continue request id 4950
Aug 26 12:39:33.671: TPLUS: Authentication continue packet generated for 4950
Aug 26 12:39:33.671: TPLUS(00001356)/0/WRITE/3AB36584: Started 5 sec timeout
Aug 26 12:39:33.671: TPLUS(00001356)/0/WRITE: wrote entire 31 bytes request
Aug 26 12:39:33.953: TPLUS(00001356)/0/READ: socket event 1
Aug 26 12:39:33.953: TPLUS(00001356)/0/READ: read entire 12 header bytes (expect 6 bytes data)
Aug 26 12:39:33.953: TPLUS(00001356)/0/READ: socket event 1
Aug 26 12:39:33.953: TPLUS(00001356)/0/READ: read entire 18 bytes response
Aug 26 12:39:33.953: TPLUS(00001356)/0/3AB36584: Processing the reply packet
Aug 26 12:39:33.953: TPLUS: Received authen response status PASS (2)
Aug 26 12:39:33.954: TPLUS: Queuing AAA Authorization request 4950 for processing
Aug 26 12:39:33.954: TPLUS(00001356) login timer started 1020 sec timeout
Aug 26 12:39:33.954: TPLUS: processing authorization request id 4950
Aug 26 12:39:33.954: TPLUS: Protocol set to None .....Skipping
Aug 26 12:39:33.954: TPLUS: Sending AV service=shell
Aug 26 12:39:33.954: TPLUS: Sending AV cmd*
Aug 26 12:39:33.954: TPLUS: Authorization request created for 4950(USER55)
Aug 26 12:39:33.955: TPLUS: using previously set server 192.168.x.x from group tacacs+
Aug 26 12:39:33.960: TPLUS(00001356)/0/NB_WAIT/3AB36584: Started 5 sec timeout
Aug 26 12:39:33.962: TPLUS(00001356)/0/NB_WAIT: socket event 2
Aug 26 12:39:33.962: TPLUS(00001356)/0/NB_WAIT: wrote entire 59 bytes request
Aug 26 12:39:33.962: TPLUS(00001356)/0/READ: socket event 1
Aug 26 12:39:33.962: TPLUS(00001356)/0/READ: Would block while reading
Aug 26 12:39:34.098: TPLUS(00001356)/0/READ: socket event 1
Aug 26 12:39:34.098: TPLUS(00001356)/0/READ: read entire 12 header bytes (expect 18 bytes data)
Aug 26 12:39:34.098: TPLUS(00001356)/0/READ: socket event 1
Aug 26 12:39:34.098: TPLUS(00001356)/0/READ: read entire 30 bytes response
Aug 26 12:39:34.098: TPLUS(00001356)/0/3AB36584: Processing the reply packet
Aug 26 12:39:34.099: TPLUS: Processed AV priv-lvl=15
Aug 26 12:39:34.099: TPLUS: received authorization response for 4950: PASS
Aug 26 12:39:34.100: TPLUS: Queuing AAA Accounting request 4950 for processing
Aug 26 12:39:34.100: TPLUS: processing accounting request id 4950
Aug 26 12:39:34.100: TPLUS: Sending AV task_id=7145
Aug 26 12:39:34.
100: TPLUS: Sending AV timezone=GMT
Aug 26 12:39:34.100: TPLUS: Sending AV service=shell
Aug 26 12:39:34.100: TPLUS: Sending AV start_time=1409056774
Aug 26 12:39:34.100: TPLUS: Accounting request created for 4950(USER55)
Aug 26 12:39:34.100: TPLUS: using previously set server 192.168.x.x from group tacacs+
Aug 26 12:39:34.106: TPLUS(00001356)/0/NB_WAIT/3A72C8D0: Started 5 sec timeout
Aug 26 12:39:34.108: TPLUS(00001356)/0/NB_WAIT: socket event 2
Aug 26 12:39:34.108: TPLUS(00001356)/0/NB_WAIT: wrote entire 103 bytes request
Aug 26 12:39:34.108: TPLUS(00001356)/0/READ: socket event 1
Aug 26 12:39:34.108: TPLUS(00001356)/0/READ: Would block while reading
Aug 26 12:39:34.114: TPLUS(00001356)/0/READ: socket event 1
Aug 26 12:39:34.114: TPLUS(00001356)/0/READ: read entire 12 header bytes (expect 5 bytes data)
Aug 26 12:39:34.114: TPLUS(00001356)/0/READ: socket event 1
Aug 26 12:39:34.114: TPLUS(00001356)/0/READ: read entire 17 bytes response
Aug 26 12:39:34.114: TPLUS(00001356)/0/3A72C8D0: 
Processing the reply packet
Aug 26 12:39:34.114: TPLUS: Received accounting response with status PASS
SW-Comms-9#sh
Command authorization failed.

Aug 26 12:39:47.222: TAC+: using previously set server 192.168.x.x from group tacacs+
Aug 26 12:39:47.222: TAC+: Opening TCP/IP to 192.168.x.x/49 timeout=5
Aug 26 12:39:47.230: TAC+: Opened TCP/IP handle 0x3BE31D1C to 192.168.x.x/49
Aug 26 12:39:47.230: TAC+: Opened 192.168.x.x index=1
Aug 26 12:39:47.230: TAC+: 192.168.x.x (4007938957) AUTHOR/START queued
Aug 26 12:39:47.430: TAC+: (4007938957) AUTHOR/START processed
Aug 26 12:39:47.430: TAC+: (-287028339): received author response status = FAIL
Aug 26 12:39:47.431: TAC+: Closing TCP/IP 0x3BE31D1C connection to 192.168.x.x/49
SW-Comms-9#sh int
Command authorization failed.

Aug 26 12:40:01.241: TAC+: using previously set server 192.168.x.x from group tacacs+
Aug 26 12:40:01.241: TAC+: Opening TCP/IP to 192.168.x.x/49 timeout=5
Aug 26 12:40:01.249: TAC+: Opened TCP/IP handle 0x3BE31D1C to 192.168.x.x/49
Aug 26 12:40:01.249: TAC+: Opened 192.168.x.x index=1
Aug 26 12:40:01.250: TAC+: 192.168.x.x (3653537180) AUTHOR/START queued
Aug 26 12:40:01.449: TAC+: (3653537180) AUTHOR/START processed
Aug 26 12:40:01.449: TAC+: (-641430116): received author response status = FAIL
Aug 26 12:40:01.450: TAC+: Closing TCP/IP 0x3BE31D1C connection to 192.168.x.x/49

[Jatin Katyal · Accepted solution]

I don't see the command and argument going in authz packet. Can you please ensure that you have your IOS device configured as per the link below.

http://www.cisco.com/c/en/us/support/docs/security/secure-access-control-system/113590-acs5-tacacs-config.html#dfgt

Check steps 34,35, 36 to ensure you have configured ACS with the right set of commands. 

http://www.cisco.com/c/en/us/support/docs/security/secure-access-control-system/113590-acs5-tacacs-config.html#ade

-Jatin

[JDMJeffy84]

Your the man! I missed out Step 24, the access rule was denying all commands!
If I could I buy you a drink right now!

Thanks

[JDMJeffy84]

Hey Jatin,

Strangely I can log into some switches and some fails gives me 'authorization failed' I managed to debug on the switch, looks like tacacs fails and drops to Local mode? The configurations are the same on all Cisco devices:

aaa new-model
aaa group server tacacs+ ACS
 server 192.168.x.x
!

tacacs-server host 192.168.x.x key 7 sharedsecret
tacacs-server directed-request

!
aaa authentication login default group ACS local
aaa authorization console
aaa authorization exec default group ACS local
aaa authorization commands 0 default group ACS local
aaa authorization commands 1 default group ACS local
aaa authorization commands 15 default group ACS local
aaa accounting exec default start-stop group ACS
aaa accounting commands 0 default start-stop group ACS
aaa accounting commands 1 default start-stop group ACS
aaa accounting commands 15 default start-stop group ACS
aaa accounting connection default start-stop group ACS
aaa accounting system default start-stop group ACS

===debug aaa authentication and debug tacacs ===

=~=~=~=~=~=~=~=~=~=~=~= PuTTY log 2014.08.27 16:42:01 =~=~=~=~=~=~=~=~=~=~=~=

18w4d: AAA/AUTHEN (686263213): status = ERROR
18w4d: AAA/AUTHEN/START (686263213): Method=LOCAL
18w4d: AAA/AUTHEN (686263213): status = GETUSER
18w4d: AAA/AUTHEN/ABORT: (686263213) because Carrier dropped.
18w4d: AAA/AUTHEN/ABORT: (686263213) because Carrier dropped.
18w4d: AAA/MEMORY: free_user (0x1C306CC) user='NULL' ruser='NULL' port='tty4' rem_addr='192.168.x.x' authen_type=ASCII service=LOGIN priv=1
18w4d: AAA: parse name=tty2 idb type=-1 tty=-1
18w4d: AAA: name=tty2 flags=0x11 type=5 shelf=0 slot=0 adapter=0 port=2 channel=0
18w4d: AAA/MEMORY: create_user (0x1C306CC) user='NULL' ruser='NULL' ds0=0 port='tty2' rem_addr='192.168.x.x' authen_type=ASCII service=LOGIN priv=1 initial_task_id='0', vrf= (id=0)
18w4d: AAA/AUTHEN/START (2389441817): port='tty2' list='' action=LOGIN service=LOGIN
18w4d: AAA/AUTHEN/START (2389441817): using "default" list
18w4d: AAA/AUTHEN/START (2389441817): Method=ACS (tacacs+)
18w4d: TAC+: send AUTHEN/START packet ver=192 id=2389441817
18w4d: TAC+: Using default tacacs server-group "ACS" list.
18w4d: TAC+: Opening TCP/IP to 192.168.x.x/49 timeout=5
18w4d: TAC+: Opened TCP/IP handle 0x1C38E58 to 192.168.x.x/49
18w4d: TAC+: 192.168.x.x (2389441817) AUTHEN/START/LOGIN/ASCII queued
18w4d: TAC+: (2389441817) AUTHEN/START/LOGIN/ASCII processed
18w4d: TAC+: decrypt: pak is unencrypted but we have a key
18w4d: TAC+: Unable to decrypt data from server.
18w4d: TAC+: Closing TCP/IP 0x1C38E58 connection to 192.168.x.x/49
18w4d: TAC+: Using default tacacs server-group "ACS" list.
18w4d: AAA/AUTHEN (2389441817): status = ERROR
18w4d: AAA/AUTHEN/START (2389441817): Method=LOCAL
18w4d: AAA/AUTHEN (2389441817): status = GETUSER
18w4d: AAA/AUTHEN/CONT (2389441817): continue_login (user='(undef)')
18w4d: AAA/AUTHEN (2389441817): status = GETUSER
18w4d: AAA/AUTHEN/CONT (2389441817): Method=LOCAL
18w4d: AAA/AUTHEN (2389441817): status = GETPASS
18w4d: AAA/AUTHEN/CONT (2389441817): continue_login (user='USER')
18w4d: AAA/AUTHEN (2389441817): status = GETPASS
18w4d: AAA/AUTHEN/CONT (2389441817): Method=LOCAL
18w4d: AAA/AUTHEN (2389441817): User not found
18w4d: AAA/AUTHEN (2389441817): status = FAIL
18w4d: AAA/AUTHEN/ABORT: (2389441817) because Unknown.
18w4d: AAA/MEMORY: free_user_quiet (0x1C306CC) user='USER' ruser='NULL' port='tty2' rem_addr='192.168.x.x' authen_type=1 service=1 priv=1
18w4d: AAA: parse name=tty2 idb type=-1 tty=-1
18w4d: AAA: name=tty2 flags=0x11 type=5 shelf=0 slot=0 adapter=0 port=2 channel=0
18w4d: AAA/MEMORY: create_user (0x1C306CC) user='NULL' ruser='NULL' ds0=0 port='tty2' rem_addr='192.168.x.x' authen_type=ASCII service=LOGIN priv=1 initial_task_id='0', vrf= (id=0)
18w4d: AAA/AUTHEN/START (103792608): port='tty2' list='' action=LOGIN service=LOGIN
18w4d: AAA/AUTHEN/START (103792608): using "default" list
18w4d: AAA/AUTHEN/START (103792608): Method=ACS (tacacs+)
18w4d: TAC+: send AUTHEN/START packet ver=192 id=103792608
18w4d: TAC+: Using default tacacs server-group "ACS" list.
18w4d: TAC+: Opening TCP/IP to 192.168.x.x/49 timeout=5
18w4d: TAC+: Opened TCP/IP handle 0x1BF408C to 192.168.x.x/49
18w4d: TAC+: 192.168.x.x (103792608) AUTHEN/START/LOGIN/ASCII queued
18w4d: TAC+: (103792608) AUTHEN/START/LOGIN/ASCII processed
18w4d: TAC+: decrypt: pak is unencrypted but we have a key
18w4d: TAC+: Unable to decrypt data from server.
18w4d: TAC+: Closing TCP/IP 0x1BF408C connection to 192.168.x.x/49
18w4d: TAC+: Using default tacacs server-group "ACS" list.
18w4d: AAA/AUTHEN (103792608): status = ERROR
18w4d: AAA/AUTHEN/START (103792608): Method=LOCAL
18w4d: AAA/AUTHEN (103792608): status = GETUSER
18w4d: AAA/AUTHEN/CONT (103792608): continue_login (user='(undef)')
18w4d: AAA/AUTHEN (103792608): status = GETUSER
18w4d: AAA/AUTHEN/CONT (103792608): Method=LOCAL
18w4d: AAA/AUTHEN/LOCAL (103792608): no username: GETUSER
18w4d: AAA/AUTHEN (103792608): status = GETUSER
18w4d: AAA/AUTHEN/CONT (103792608): continue_login (user='')
18w4d: AAA/AUTHEN (103792608): status = GETUSER
18w4d: AAA/AUTHEN/CONT (103792608): Method=LOCAL
18w4d: AAA/AUTHEN/LOCAL (103792608): no username: GETUSER
18w4d: AAA/AUTHEN (103792608): status = GETUSER
18w4d: AAA/AUTHEN/ABORT: (103792608) because Carrier dropped.

Thanks