[tac_plus] Tac Plus Auth Error with IOS 16

Tue Nov 21 19:57:27 UTC 2017

++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.
> > >
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://www.shrubbery.net/pipermail/tac_plus/attachments/20171121/dbdeb26d/attachment.html>