[tac_plus] Tac Plus Auth Error with IOS 16

Tue Nov 21 20:06:09 UTC 2017

Are you saying this could be a do_auth problem?  I do not have anything IOS
XE 16 to test with.

On Tue, Nov 21, 2017 at 12:57 PM, Andrew Villano <andrew.villano at gmail.com>
wrote:

> ++Reply_All...
>
> It's not at the network layer because it will connect intermittently,
> especially when using another (more privileged account). The only
> difference between the two accounts is the filtering I do in do_auth.conf
> and the fact that one also exists as a local account.
>
>
> Nov 21 18:37:26.296: AAA/BIND(00000FE2): Bind i/f
> Nov 21 18:37:26.297: AAA/AUTHEN/LOGIN (00000FE2): Pick method list
> 'default'
> Nov 21 18:37:26.297: TPLUS: Queuing AAA Authentication request 4066 for
> processing
> Nov 21 18:37:26.298: TPLUS(00000FE2) login timer started 1020 sec timeout
> Nov 21 18:37:26.299: TPLUS: processing authentication start request id 4066
> Nov 21 18:37:26.299: TPLUS: Authentication start packet created for
> 4066(root)
> Nov 21 18:37:26.300: TPLUS: Using server **tacacs server ip**
> Nov 21 18:37:26.302: TPLUS(00000FE2)/0/NB_WAIT/FF97E18E08: Started 5 sec
> timeout
> Nov 21 18:37:26.303: TPLUS(00000FE2)/0/NB_WAIT: socket event 2
> Nov 21 18:37:26.304: TPLUS(00000FE2)/0/NB_WAIT: wrote entire 41 bytes
> request
> Nov 21 18:37:26.304: TPLUS(00000FE2)/0/READ: socket event 1
> Nov 21 18:37:26.304: TPLUS(00000FE2)/0/READ: Would block while reading
> Nov 21 18:37:26.313: TPLUS(00000FE2)/0/READ: socket event 1
> Nov 21 18:37:26.313: TPLUS(00000FE2)/0/READ: read entire 12 header bytes
> (expect 16 bytes data)
> Nov 21 18:37:26.313: TPLUS(00000FE2)/0/READ: socket event 1
> Nov 21 18:37:26.313: TPLUS(00000FE2)/0/READ: read entire 28 bytes response
> Nov 21 18:37:26.313: TPLUS(00000FE2) login timer stopped
> Nov 21 18:37:26.314: TPLUS(00000FE2)/0/FF97E18E08: Processing the reply
> packet
> Nov 21 18:37:26.314: TPLUS: Received authen response status GET_PASSWORD
> (8)
> Nov 21 18:37:26.314: TPLUS(00000FE2)/0/None: Started 120 sec timeout
> Nov 21 18:37:29.546: TPLUS: Queuing AAA Authentication request 4066 for
> processing
> Nov 21 18:37:29.547: TPLUS(00000FE2) login timer started 1020 sec timeout
> Nov 21 18:37:29.547: TPLUS: processing authentication continue request id
> 4066
> Nov 21 18:37:29.548: TPLUS: Authentication continue packet generated for
> 4066
> Nov 21 18:37:29.548: TPLUS(00000FE2)/0/None: Timer Stoped
> Nov 21 18:37:29.549: TPLUS(00000FE2)/0/WRITE/FF97AEA8C0: Started 5 sec
> timeout
> Nov 21 18:37:29.549: TPLUS(00000FE2)/0/WRITE: wrote entire 24 bytes request
> Nov 21 18:37:29.571: TPLUS(00000FE2)/0/READ: socket event 1
> Nov 21 18:37:29.571: TPLUS(00000FE2)/0/READ: read entire 12 header bytes
> (expect 6 bytes data)
> Nov 21 18:37:29.571: TPLUS(00000FE2)/0/READ: socket event 1
> Nov 21 18:37:29.572: TPLUS(00000FE2)/0/READ: read entire 18 bytes response
> Nov 21 18:37:29.572: TPLUS(00000FE2) login timer stopped
> Nov 21 18:37:29.572: TPLUS(00000FE2)/0/FF97AEA8C0: Processing the reply
> packet
> Nov 21 18:37:29.572: TPLUS: Received authen response status PASS (2)
> Nov 21 18:37:29.573: TPLUS: Invalid Client information received as input
> Nov 21 18:37:29.627: TPLUS(00000FE2) login timer stopped
> Nov 21 18:37:29.627: TPLUS: Invalid Client information received as input
> Nov 21 18:40:03.178: AAA/BIND(00000FE3): Bind i/f
> Nov 21 18:40:03.178: AAA/AUTHEN/LOGIN (00000FE3): Pick method list
> 'default'
> Nov 21 18:40:03.179: TPLUS: Queuing AAA Authentication request 4067 for
> processing
> Nov 21 18:40:03.179: TPLUS(00000FE3) login timer started 1020 sec timeout
> Nov 21 18:40:03.179: TPLUS: processing authentication start request id 4067
> Nov 21 18:40:03.179: TPLUS: Authentication start packet created for
> 4067(rancid)
> Nov 21 18:40:03.180: TPLUS: Using server **tacacs server ip**
> Nov 21 18:40:03.181: TPLUS(00000FE3)/0/NB_WAIT/FF97D911E8: Started 5 sec
> timeout
> Nov 21 18:40:03.183: TPLUS(00000FE3)/0/NB_WAIT: socket event 2
> Nov 21 18:40:03.183: T+: Version 192 (0xC0), type 1, seq 1, encryption 1,
> SC 0
> Nov 21 18:40:03.183: T+: session_id 2506212375 <(250)%20621-2375>
> (0x9561C417), dlen 31 (0x1F)
> Nov 21 18:40:03.183: T+: type:AUTHEN/START, priv_lvl:1 action:LOGIN ascii
> Nov 21 18:40:03.183: T+: svc:LOGIN user_len:6 port_len:4 (0x4)
> raddr_len:13 (0xD) data_len:0
> Nov 21 18:40:03.183: T+: user:  rancid
> Nov 21 18:40:03.183: T+: port:  tty2
> Nov 21 18:40:03.183: T+: rem_addr:  **client ip**
> Nov 21 18:40:03.183: T+: data:
> Nov 21 18:40:03.183: T+: End Packet
> Nov 21 18:40:03.184: TPLUS(00000FE3)/0/NB_WAIT: wrote entire 43 bytes
> request
> Nov 21 18:40:03.184: TPLUS(00000FE3)/0/READ: socket event 1
> Nov 21 18:40:03.184: TPLUS(00000FE3)/0/READ: Would block while reading
> Nov 21 18:40:03.190: TPLUS(00000FE3)/0/READ: socket event 1
> Nov 21 18:40:03.190: TPLUS(00000FE3)/0/READ: read entire 12 header bytes
> (expect 16 bytes data)
> Nov 21 18:40:03.190: TPLUS(00000FE3)/0/READ: socket event 1
> Nov 21 18:40:03.190: TPLUS(00000FE3)/0/READ: read entire 28 bytes response
> Nov 21 18:40:03.191: T+: Version 192 (0xC0), type 1, seq 2, encryption 1,
> SC 0
> Nov 21 18:40:03.191: T+: session_id 2506212375 <(250)%20621-2375>
> (0x9561C417), dlen 16 (0x10)
> Nov 21 18:40:03.191: T+: AUTHEN/REPLY status:5 flags:0x1 msg_len:10,
> data_len:0
> Nov 21 18:40:03.191: T+: msg:  Password:
> Nov 21 18:40:03.191: T+: data:
> Nov 21 18:40:03.191: T+: End Packet
> Nov 21 18:40:03.191: TPLUS(00000FE3) login timer stopped
> Nov 21 18:40:03.191: TPLUS(00000FE3)/0/FF97D911E8: Processing the reply
> packet
> Nov 21 18:40:03.191: TPLUS: Received authen response status GET_PASSWORD
> (8)
> Nov 21 18:40:03.192: TPLUS(00000FE3)/0/None: Started 120 sec timeout
> Nov 21 18:40:06.197: AAA/AUTHEN/LOGIN (00000FE3): Pick method list
> 'default'
> Nov 21 18:40:06.197: TPLUS: Queuing AAA Authentication request 4067 for
> processing
> Nov 21 18:40:06.198: TPLUS(00000FE3) login timer started 1020 sec timeout
> Nov 21 18:40:06.198: TPLUS: processing authentication start request id 4067
> Nov 21 18:40:06.198: TPLUS: Authentication start packet created for
> 4067(rancid)
> Nov 21 18:40:06.198: TPLUS: Using server **tacacs server ip**
> Nov 21 18:40:06.200: TPLUS(00000FE3)/1/NB_WAIT/FF97AEA8C0: Started 5 sec
> timeout
> Nov 21 18:40:06.201: TPLUS(00000FE3)/1/NB_WAIT: socket event 2
> Nov 21 18:40:06.201: T+: Version 192 (0xC0), type 1, seq 1, encryption 1,
> SC 0
> Nov 21 18:40:06.201: T+: session_id 795748828 (0x2F6E29DC), dlen 31 (0x1F)
> Nov 21 18:40:06.201: T+: type:AUTHEN/START, priv_lvl:1 action:LOGIN ascii
> Nov 21 18:40:06.201: T+: svc:LOGIN user_len:6 port_len:4 (0x4)
> raddr_len:13 (0xD) data_len:0
> Nov 21 18:40:06.201: T+: user:  rancid
> Nov 21 18:40:06.202: T+: port:  tty2
> Nov 21 18:40:06.202: T+: rem_addr:  **client ip**
> Nov 21 18:40:06.202: T+: data:
> Nov 21 18:40:06.202: T+: End Packet
> Nov 21 18:40:06.204: TPLUS(00000FE3)/1/NB_WAIT: wrote entire 43 bytes
> request
> Nov 21 18:40:06.204: TPLUS(00000FE3)/1/READ: socket event 1
> Nov 21 18:40:06.204: TPLUS(00000FE3)/1/READ: Would block while reading
> Nov 21 18:40:11.199: TPLUS(00000FE3)/1/READ/FF97AEA8C0: timed out
> Nov 21 18:40:11.199: TPLUS: Authentication start packet created for
> 4067(rancid)
> Nov 21 18:40:11.199: TPLUS(00000FE3)/1/READ/FF97AEA8C0: timed out, clean
> up
> Nov 21 18:40:11.200: TPLUS(00000FE3) login timer stopped
> Nov 21 18:40:11.200: TPLUS(00000FE3)/1/FF97AEA8C0: Processing the reply
> packet
> Nov 21 18:40:11.200: TPLUS: Invalid Client information received as input
> Nov 21 18:40:14.207: AAA/AUTHEN/LOGIN (00000FE3): Pick method list
> 'default'
> Nov 21 18:40:14.208: TPLUS: Queuing AAA Authentication request 4067 for
> processing
> Nov 21 18:40:14.208: TPLUS(00000FE3) login timer started 1020 sec timeout
> Nov 21 18:40:14.208: TPLUS: processing authentication start request id 4067
> Nov 21 18:40:14.208: TPLUS: Authentication start packet created for
> 4067(rancid)
> Nov 21 18:40:14.209: TPLUS: Using server **tacacs server ip**
> Nov 21 18:40:14.210: TPLUS(00000FE3)/1/NB_WAIT/FF97AEA8C0: Started 5 sec
> timeout
> Nov 21 18:40:14.211: TPLUS(00000FE3)/1/NB_WAIT: socket event 2
> Nov 21 18:40:14.211: T+: Version 192 (0xC0), type 1, seq 1, encryption 1,
> SC 0
> Nov 21 18:40:14.211: T+: session_id 2016212721 <(201)%20621-2721>
> (0x782CF6F1), dlen 31 (0x1F)
> Nov 21 18:40:14.211: T+: type:AUTHEN/START, priv_lvl:1 action:LOGIN ascii
> Nov 21 18:40:14.212: T+: svc:LOGIN user_len:6 port_len:4 (0x4)
> raddr_len:13 (0xD) data_len:0
> Nov 21 18:40:14.212: T+: user:  rancid
> Nov 21 18:40:14.212: T+: port:  tty2
> Nov 21 18:40:14.212: T+: rem_addr:  **client ip**
> Nov 21 18:40:14.212: T+: data:
> Nov 21 18:40:14.212: T+: End Packet
> Nov 21 18:40:14.212: TPLUS(00000FE3)/1/NB_WAIT: wrote entire 43 bytes
> request
> Nov 21 18:40:14.212: TPLUS(00000FE3)/1/READ: socket event 1
> Nov 21 18:40:14.213: TPLUS(00000FE3)/1/READ: Would block while reading
> Nov 21 18:40:19.211: TPLUS(00000FE3)/1/READ/FF97AEA8C0: timed out
> Nov 21 18:40:19.211: TPLUS: Authentication start packet created for
> 4067(rancid)
> Nov 21 18:40:19.211: TPLUS(00000FE3)/1/READ/FF97AEA8C0: timed out, clean
> up
> Nov 21 18:40:19.211: TPLUS(00000FE3) login timer stopped
> Nov 21 18:40:19.211: TPLUS(00000FE3)/1/FF97AEA8C0: Processing the reply
> packet
> Nov 21 18:40:19.212: TPLUS: Invalid Client information received as input
> Nov 21 18:40:26.559: AAA/BIND(00000FE4): Bind i/f
> Nov 21 18:40:26.559: AAA/AUTHEN/LOGIN (00000FE4): Pick method list
> 'default'
> Nov 21 18:40:26.560: TPLUS: Queuing AAA Authentication request 4068 for
> processing
> Nov 21 18:40:26.560: TPLUS(00000FE4) login timer started 1020 sec timeout
> Nov 21 18:40:26.560: TPLUS: processing authentication start request id 4068
> Nov 21 18:40:26.561: TPLUS: Authentication start packet created for
> 4068(root)
> Nov 21 18:40:26.561: TPLUS: Using server **tacacs server ip**
> Nov 21 18:40:26.563: TPLUS(00000FE4)/1/NB_WAIT/FF97E18E08: Started 5 sec
> timeout
> Nov 21 18:40:26.564: TPLUS(00000FE4)/1/NB_WAIT: socket event 2
> Nov 21 18:40:26.565: T+: Version 192 (0xC0), type 1, seq 1, encryption 1,
> SC 0
> Nov 21 18:40:26.565: T+: session_id 2166987313 <(216)%20698-7313>
> (0x81299A31), dlen 29 (0x1D)
> Nov 21 18:40:26.566: T+: type:AUTHEN/START, priv_lvl:1 action:LOGIN ascii
> Nov 21 18:40:26.566: T+: svc:LOGIN user_len:4 port_len:4 (0x4)
> raddr_len:13 (0xD) data_len:0
> Nov 21 18:40:26.566: T+: user:  root
> Nov 21 18:40:26.567: T+: port:  tty2
> Nov 21 18:40:26.567: T+: rem_addr:  **client ip**
> Nov 21 18:40:26.568: T+: data:
> Nov 21 18:40:26.568: T+: End Packet
> Nov 21 18:40:26.568: TPLUS(00000FE4)/1/NB_WAIT: wrote entire 41 bytes
> request
> Nov 21 18:40:26.568: TPLUS(00000FE4)/1/READ: socket event 1
> Nov 21 18:40:26.568: TPLUS(00000FE4)/1/READ: Would block while reading
> Nov 21 18:40:31.563: TPLUS(00000FE4)/1/READ/FF97E18E08: timed out
> Nov 21 18:40:31.564: TPLUS: Authentication start packet created for
> 4068(root)
> Nov 21 18:40:31.564: TPLUS(00000FE4)/1/READ/FF97E18E08: timed out, clean
> up
> Nov 21 18:40:31.565: TPLUS(00000FE4) login timer stopped
> Nov 21 18:40:31.565: TPLUS(00000FE4)/1/FF97E18E08: Processing the reply
> packet
> Nov 21 18:40:31.566: TPLUS: Invalid Client information received as input
> Nov 21 18:40:34.496: T+: Version 192 (0xC0), type 2, seq 1, encryption 1,
> SC 0
> Nov 21 18:40:34.496: T+: session_id 235734674 (0xE0D0692), dlen 48 (0x30)
> Nov 21 18:40:34.496: T+: AUTHOR, priv_lvl:1, authen:1 method:local
> Nov 21 18:40:34.497: T+: svc:1 user_len:4 port_len:4 rem_addr_len:13
> arg_cnt:2
> Nov 21 18:40:34.497: T+: user:  root
> Nov 21 18:40:34.497: T+: port:  tty2
> Nov 21 18:40:34.497: T+: rem_addr:  **client ip**
> Nov 21 18:40:34.497: T+: arg[0]: size:13 service=shell
> Nov 21 18:40:34.497: T+: arg[1]: size:4 cmd*
> Nov 21 18:40:34.497: T+: End Packet
> Nov 21 18:40:39.494: TPLUS(00000FE4) login timer stopped
> Nov 21 18:40:39.497: TPLUS: Invalid Client information received as input
> Nov 21 18:42:03.191: TPLUS: Client is not responding Forcefully closing
> the socket
> Nov 21 18:42:03.191: TPLUS: Details of client session
> Nov 21 18:42:03.191:  Client PID : 393
> Nov 21 18:42:03.191:  Allocator PC : 0
> Nov 21 18:42:03.192:  Transaction Type : Authentication
> Nov 21 18:42:03.192:  Transaction Status : GET_PASSWORD
> Nov 21 18:42:03.192:  Service : none
> Nov 21 18:42:03.192:  Protocol : none
>
> On Tue, Nov 21, 2017 at 12:50 PM, heasley <heas at shrubbery.net> wrote:
>
>> Tue, Nov 21, 2017 at 09:42:09AM -0500, Andrew Villano:
>> > Removed -L since that was adding a bunch of noise.
>> >
>> > Found something worth mentioning when adding -d256:
>> >
>> > **client ip**: Illegal major version specified: found 97 wanted 192
>> > **client ip**: disconnect
>>
>> yeah, weird.  the debug o/p looks normal to me.
>>
>> > Turned on debug aaa authentication and debug tacacs authentication:
>> >
>> > Nov 21 14:36:49.113: TPLUS(00000FE0)/1/READ/FF96035DF8: timed out
>> > Nov 21 14:36:49.113: TPLUS: Authentication start packet created for
>> > 4064(rancid)
>> > Nov 21 14:36:49.113: TPLUS(00000FE0)/1/READ/FF96035DF8: timed out,
>> clean up
>> > Nov 21 14:36:49.113: TPLUS(00000FE0) login timer stopped
>> > Nov 21 14:36:49.113: TPLUS(00000FE0)/1/FF96035DF8: Processing the reply
>> > packet
>> > Nov 21 14:36:49.114: TPLUS: Invalid Client information received as input
>> > Nov 21 14:36:52.119: AAA/AUTHEN/LOGIN (00000FE0): Pick method list
>> > 'default'
>> > Nov 21 14:36:52.120: TPLUS: Queuing AAA Authentication request 4064 for
>> > processing
>> > Nov 21 14:36:52.120: TPLUS(00000FE0) login timer started 1020 sec
>> timeout
>> > Nov 21 14:36:52.120: TPLUS: processing authentication start request id
>> 4064
>> > Nov 21 14:36:52.120: TPLUS: Authentication start packet created for
>> > 4064(rancid)
>> > Nov 21 14:36:52.121: TPLUS: Using server **tacacs server**
>> > Nov 21 14:36:52.122: TPLUS(00000FE0)/1/NB_WAIT/FF97B1F858: Started 5
>> sec
>> > timeout
>> > Nov 21 14:36:52.125: TPLUS(00000FE0)/1/NB_WAIT: socket event 2
>> > Nov 21 14:36:52.126: TPLUS(00000FE0)/1/NB_WAIT: wrote entire 43 bytes
>> > request
>> > Nov 21 14:36:52.126: TPLUS(00000FE0)/1/READ: socket event 1
>> > Nov 21 14:36:52.127: TPLUS(00000FE0)/1/READ: Would block while reading
>> > Nov 21 14:36:57.122: TPLUS(00000FE0)/1/READ/FF97B1F858: timed out
>>
>> why did it timeout.  do you have filters somewhere that are interfering?
>> or perhaps a routing problem or duplicate address?  maybe add aaa packet
>> debugging.
>>
>> > Nov 21 14:36:57.122: TPLUS: Authentication start packet created for
>> > 4064(rancid)
>> > Nov 21 14:36:57.123: TPLUS(00000FE0)/1/READ/FF97B1F858: timed out,
>> clean up
>> > Nov 21 14:36:57.123: TPLUS(00000FE0) login timer stopped
>> > Nov 21 14:36:57.123: TPLUS(00000FE0)/1/FF97B1F858: Processing the reply
>> > packet
>> > Nov 21 14:36:57.124: TPLUS: Invalid Client information received as input
>> >
>> >
>> >
>> > On Mon, Nov 20, 2017 at 8:56 PM, heasley <heas at shrubbery.net> wrote:
>> >
>> > > Mon, Nov 20, 2017 at 02:21:53PM -0700, Daniel Schmidt:
>> > > > wild guess:
>> > > >
>> > > > try adding pap = cleartext "blahblahblah"
>> > > >
>> > >
>> > > yeah, or try it with -d 8 -d 256.  find the service type, because this
>> > > is weird:
>> > >
>> > > > > Nov 20 15:43:09.240: TPLUS: Details of client session
>> > > > > Nov 20 15:43:09.240:  Client PID : 502
>> > > > > Nov 20 15:43:09.240:  Allocator PC : 0
>> > > > > Nov 20 15:43:09.240:  Transaction Type : Authentication
>> > > > > Nov 20 15:43:09.240:  Transaction Status : GET_PASSWORD
>> > > > > Nov 20 15:43:09.240:  Service : none        <<<<<<<<<<<<<<
>> > > > > Nov 20 15:43:09.240:  Protocol : none
>> > > > > Nov 20 15:47:59.067: TPLUS(00000FCA) login timer stopped
>> > > > > Nov 20 15:47:59.067: TPLUS(00000FCA)/0/None: Started 120 sec
>> timeout
>> > >                                          ^ wonder what the 0 is.
>> > >
>>
>
>

-- 

E-Mail to and from me, in connection with the transaction 
of public business, is subject to the Wyoming Public Records 
Act and may be disclosed to third parties.
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://www.shrubbery.net/pipermail/tac_plus/attachments/20171121/ea29caa2/attachment.html>