Hello all,
I'm doing a trial run of CPPM in hopes to replace Cisco ACS. I really like CPPM so far, however I'm experiencing what seems to be a frustrating bug or configuration issue.
When trying to log into a Cisco switch configured for TACACS login, my initial login never works, however on the second password attempt it authenticates fine.View from switch CLI
When I check Alert Tracker, I get a login status REJECT, I then pull up the record and see the following errors:Initial Login Alert Tracker Record - AlertsI see that it's matching my service but failing after that because it doesn't match my source, role, profiles, etc.
Initial Login Record - Policies
If I click show logs, this is all I get:
Request log details for session: T0000003a-01-5afb08bfTime Message
2018-05-15 11:20:15,788 | [RequestHandler-1-0x7f4b007e3700 r=psauto-1526398931-95 h=223 r=T0000003a-01-5afb08bf] INFO Core.ServiceReqHandler - Service classification result = Cisco-ND-Auth |
2018-05-15 11:20:15,788 | [AAAModuleThread-0x7fde293a0700 h=461 c=T0000003a-01-5afb08bf] INFO AAA.ServiceReqHandler - handleXpipClientResponseEv: Got ServiceObj from ServiceTables for Cisco-ND-Auth |
On the second password entry all works fine though!
As you can see, it passed the shell fine.
Furthermore, I can pull up show logs and I get the following:
Request log details for session: T0000003b-01-5afb08c9Time Message
2018-05-15 11:20:25,292 | [RequestHandler-1-0x7f4b007e3700 r=psauto-1526398931-96 h=223 r=T0000003b-01-5afb08c9] INFO Core.ServiceReqHandler - Service classification result = Cisco-ND-Auth |
2018-05-15 11:20:25,292 | [AAAModuleThread-0x7fde293a0700 h=463 c=T0000003b-01-5afb08c9] INFO AAA.ServiceReqHandler - handleXpipClientResponseEv: Got ServiceObj from ServiceTables for Cisco-ND-Auth |
2018-05-15 11:20:28,065 | [RequestHandler-1-0x7f4b007e3700 r=psauto-1526398931-97 h=239 r=T0000003b-01-5afb08c9] WARN IAT.XpipIATBuilder - populateSoHFromHealthStateCache: Skip looking for SoH in cache since username is not present/empty in request |
2018-05-15 11:20:28,065 | [RequestHandler-1-0x7f4b007e3700 r=psauto-1526398931-97 h=239 r=T0000003b-01-5afb08c9] WARN Common.MacAddrAttrProvider - HostMac missing, not populating different mac representations |
2018-05-15 11:20:28,065 | [RequestHandler-1-0x7f4b007e3700 r=psauto-1526398931-97 h=239 r=T0000003b-01-5afb08c9] INFO TAT.TagAttrTableUtil - buildTagAttrTableInput: Connection:Client-Mac-Address is not found |
2018-05-15 11:20:28,065 | [RequestHandler-1-0x7f4b007e3700 r=psauto-1526398931-97 h=239 r=T0000003b-01-5afb08c9] INFO TAT.AluTagAttrHolderBuilder - buildAttrHolder: Tags cannot be built for instanceId=0 (NULL AuthLocalUser) |
2018-05-15 11:20:28,065 | [RequestHandler-1-0x7f4b007e3700 r=psauto-1526398931-97 h=239 r=T0000003b-01-5afb08c9] INFO TAT.GuTagAttrHolderBuilder - buildAttrHolder: Tags cannot be built for instanceId=0 (NULL GuestUser) |
2018-05-15 11:20:28,065 | [RequestHandler-1-0x7f4b007e3700 r=psauto-1526398931-97 h=239 r=T0000003b-01-5afb08c9] INFO TAT.EndpointTagAttrHolderBuilder - buildAttrHolder: Tags cannot be built for instanceId=0 (NULL Endpoint) |
2018-05-15 11:20:28,065 | [RequestHandler-1-0x7f4b007e3700 r=psauto-1526398931-97 h=239 r=T0000003b-01-5afb08c9] INFO TAT.OnboardTagAttrHolderBuilder - buildAttrHolder: Tags cannot be built for instanceId=0 (NULL Onboard Device User) |
2018-05-15 11:20:28,066 | [RequestHandler-1-0x7f4b007e3700 h=635 c=T0000003b-01-5afb08c9] INFO Core.PETaskScheduler - *** PE_TASK_SCHEDULE_TACACS Started *** |
2018-05-15 11:20:28,066 | [RequestHandler-1-0x7f4b007e3700 h=635 c=T0000003b-01-5afb08c9] INFO Core.PETaskScheduler - ** Starting PETaskRoleMapping ** |
2018-05-15 11:20:28,067 | [RequestHandler-1-0x7f4b007e3700 h=636 c=T0000003b-01-5afb08c9] INFO Core.PETaskRoleMapping - Roles: TACACS Super Admin], User Authenticated] |
2018-05-15 11:20:28,067 | [RequestHandler-1-0x7f4b007e3700 r=T0000003b-01-5afb08c9 h=635 c=T0000003b-01-5afb08c9] INFO Core.PETaskScheduler - ** Completed PETaskRoleMapping ** |
2018-05-15 11:20:28,067 | [RequestHandler-1-0x7f4b007e3700 r=T0000003b-01-5afb08c9 h=635 c=T0000003b-01-5afb08c9] INFO Core.PETaskScheduler - ** Starting PETaskEnforcement ** |
2018-05-15 11:20:28,068 | [RequestHandler-1-0x7f4b007e3700 h=638 c=T0000003b-01-5afb08c9] INFO Core.PETaskEnforcement - EnfProfiles: Cisco-Priv-Shell |
2018-05-15 11:20:28,068 | [RequestHandler-1-0x7f4b007e3700 r=T0000003b-01-5afb08c9 h=635 c=T0000003b-01-5afb08c9] INFO Core.PETaskScheduler - ** Completed PETaskEnforcement ** |
2018-05-15 11:20:28,068 | [RequestHandler-1-0x7f4b007e3700 r=T0000003b-01-5afb08c9 h=635 c=T0000003b-01-5afb08c9] INFO Core.PETaskScheduler - ** Starting PETaskSessionLog ** |
2018-05-15 11:20:28,068 | [RequestHandler-1-0x7f4b007e3700 r=T0000003b-01-5afb08c9 h=635 c=T0000003b-01-5afb08c9] INFO Core.PETaskScheduler - ** Starting PETaskOutputPolicyRes ** |
2018-05-15 11:20:28,069 | [RequestHandler-1-0x7f4b007e3700 r=T0000003b-01-5afb08c9 h=635 c=T0000003b-01-5afb08c9] INFO Core.PETaskScheduler - ** Completed PETaskOutputPolicyRes ** |
2018-05-15 11:20:28,069 | [RequestHandler-1-0x7f4b007e3700 r=T0000003b-01-5afb08c9 h=635 c=T0000003b-01-5afb08c9] INFO Core.PETaskScheduler - ** Completed PETaskSessionLog ** |
2018-05-15 11:20:28,069 | [RequestHandler-1-0x7f4b007e3700 r=T0000003b-01-5afb08c9 h=635 c=T0000003b-01-5afb08c9] INFO Core.PETaskScheduler - *** PE_TASK_SCHEDULE_TACACS Completed *** |
So it seems like all is well, however my first authentication attempt is bombing somewhere, and I'd imagine throwing some kind of application exception that I cannot see. No idea what is causing it, or how to fix it.
If I log in successfully, I can log back into the same device successfully on the first attempt, it seems to be some sort of cached process that fails initially, then works, then stays cached for about 60 seconds or so, because after that, it starts failing again.
HELP!
Thanks,
Ryan