I now see/understand this is for the authentication of the AP to the wired network, not for wireless clients.
Is EAP-FAST the only method for APs to authenticate to the network? I'm not familiar with Cisco APs, apologies if this is a silly question.
------------------------------
Herman Robers
------------------------
If you have urgent issues, always contact your Aruba partner, distributor, or Aruba TAC Support. Check
https://www.arubanetworks.com/support-services/contact-support/ for how to contact Aruba TAC. Any opinions expressed here are solely my own and not necessarily that of Hewlett Packard Enterprise or Aruba Networks.
In case your problem is solved, please invest the time to post a follow-up with the information on how you solved it. Others can benefit from that.
------------------------------
Original Message:
Sent: Jul 21, 2022 10:47 PM
From: Michael Murphy
Subject: Clearpass EAP-FAST with Cisco APs
I have a TAC case open for exactly this issue at the moment. CISCO 9100 WAP authenticating on an Aruba 9300 switch with Clearpass as the authenticator.
The credentials are correct, the TLSv1.2 negotiation is correct, but the WAP seems to send something back to Clearpass which it doesn't understand. Found this in the WAP debugg.
[*07/22/2022 02:05:25.7856] hostapd:EAP-MSCHAPV2: Authentication succeeded
[*07/22/2022 02:05:25.7856] hostapd:EAP-FAST: Add EAP-Payload TLV
[*07/22/2022 02:05:25.7856] EAP-FAST: Encrypting Phase 2 data - hexdump(len=10): [REMOVED]
[*07/22/2022 02:05:25.7856] hostapd:OpenSSL: TX ver=0x0 content_type=256
[*07/22/2022 02:05:25.7856] hostapd:SSL: 39 bytes left to be sent out (of total 39 bytes)
[*07/22/2022 02:05:25.7856] hostapd:EAP: method process -> ignore=FALSE methodState=MAY_CONT decision=FAIL eapRespData=0x556bd84830
[*07/22/2022 02:05:25.7856] hostapd:EAP: EAP entering state SEND_RESPONSE
[*07/22/2022 02:05:25.7856] hostapd:EAP: EAP entering state IDLE
[*07/22/2022 02:05:25.7856] hostapd:EAPOL: SUPP_BE entering state RESPONSE
[*07/22/2022 02:05:25.7856] hostapd:EAPOL: txSuppRsp
[*07/22/2022 02:05:25.7856] hostapd:TX EAPOL: dst=01:80:c2:00:00:03
[*07/22/2022 02:05:25.7856] hostapd:EAPOL: SUPP_BE entering state RECEIVE
[*07/22/2022 02:05:25.7896] hostapd:l2_packet_receive: l2=0x6bd7de00 ctx=0x556bd7d130 sock=5
[*07/22/2022 02:05:25.7896] hostapd:dot1x: RX EAPOL from 44:5b:ed:2b:bb:75
[*07/22/2022 02:05:25.7896] hostapd:EAPOL: Received EAP-Packet frame
[*07/22/2022 02:05:25.7896] hostapd:EAPOL: SUPP_BE entering state REQUEST
[*07/22/2022 02:05:25.7896] hostapd:EAPOL: getSuppRsp
[*07/22/2022 02:05:25.7896] hostapd:EAP: EAP entering state RECEIVED
[*07/22/2022 02:05:25.7896] hostapd:EAP: Received EAP-Request id=63 method=43 vendor=0 vendorMethod=0
[*07/22/2022 02:05:25.7896] hostapd:EAP: EAP entering state METHOD
[*07/22/2022 02:05:25.7896] hostapd:SSL: Received packet(len=105) - Flags 0x81
[*07/22/2022 02:05:25.7896] hostapd:SSL: TLS Message Length: 95
[*07/22/2022 02:05:25.7896] hostapd:EAP-FAST: Received 95 bytes encrypted data for Phase 2
[*07/22/2022 02:05:25.7896] hostapd:OpenSSL: RX ver=0x0 content_type=256
[*07/22/2022 02:05:25.7896] hostapd:EAP-FAST: Received Phase 2: TLV type 10 length 2 (mandatory)
[*07/22/2022 02:05:25.7896] EAP-FAST: Intermediate Result TLV - hexdump(len=2): 00 01
[*07/22/2022 02:05:25.7896] hostapd:EAP-FAST: Intermediate Result: Success
[*07/22/2022 02:05:25.7896] hostapd:EAP-FAST: Received Phase 2: TLV type 12 length 56 (mandatory)
[*07/22/2022 02:05:25.7896] hostapd:EAP-FAST: Crypto-Binding TLV: Version 1 Received Version 1 SubType 0
[*07/22/2022 02:05:25.7896] hostapd:EAP-FAST: Determining CMK[1] for Compound MIC calculation
[*07/22/2022 02:05:25.7906] EAP-MSCHAPV2: Derived key - hexdump(len=32): [REMOVED]
[*07/22/2022 02:05:25.7906] hostapd:EAP-FAST: Compound MAC did not match
[*07/22/2022 02:05:25.7906] hostapd:EAP-FAST: Add Intermediate Result TLV(status=2)
[*07/22/2022 02:05:25.7906] hostapd:EAP-FAST: Add Result TLV(status=2)
[*07/22/2022 02:05:25.7906] EAP-FAST: Encrypting Phase 2 data - hexdump(len=12): [REMOVED]
[*07/22/2022 02:05:25.7906] hostapd:OpenSSL: TX ver=0x0 content_type=256
[*07/22/2022 02:05:25.7906] hostapd:SSL: 41 bytes left to be sent out (of total 41 bytes)
[*07/22/2022 02:05:25.7906] hostapd:EAP: method process -> ignore=FALSE methodState=MAY_CONT decision=FAIL eapRespData=0x556bd85e00
[*07/22/2022 02:05:25.7906] hostapd:EAP: EAP entering state SEND_RESPONSE
[*07/22/2022 02:05:25.7906] hostapd:EAP: EAP entering state IDLE
[*07/22/2022 02:05:25.7906] hostapd:EAPOL: SUPP_BE entering state RESPONSE
[*07/22/2022 02:05:25.7906] hostapd:EAPOL: txSuppRsp
[*07/22/2022 02:05:25.7906] hostapd:TX EAPOL: dst=01:80:c2:00:00:03
[*07/22/2022 02:05:25.7906] hostapd:EAPOL: SUPP_BE entering state RECEIVE
[*07/22/2022 02:05:27.4206] hostapd:l2_packet_receive: l2=0x6bd7de00 ctx=0x556bd7d130 sock=5
[*07/22/2022 02:05:27.4206] hostapd:dot1x: RX EAPOL from 44:5b:ed:2b:bb:75
[*07/22/2022 02:05:27.4206] hostapd:EAPOL: Received EAP-Packet frame
[*07/22/2022 02:05:27.4206] hostapd:EAPOL: SUPP_BE entering state REQUEST
[*07/22/2022 02:05:27.4206] hostapd:EAPOL: getSuppRsp
[*07/22/2022 02:05:27.4206] hostapd:EAP: EAP entering state RECEIVED
[*07/22/2022 02:05:27.4206] hostapd:EAP: Received EAP-Failure
[*07/22/2022 02:05:27.4206] hostapd:EAP: Status notification: completion (param=failure)
[*07/22/2022 02:05:27.4206] hostapd:EAP: EAP entering state FAILURE
That seems to say the Client/WAP tried to do something with the data received from the Clearapss to generate a "Compound MAC" which must be used in the EAP-FAST protocol and it didn't match/compute correctly. The client/WAP sent back a TLV to say so, but Clearpass didn't understand it.
As for the security implications of using EAP-FAST, I understand it's not the best method to use from a security perspective, but if somebody is determined enough to remove a WAP from the ceiling (or has access to the switch) to get access to the cable, then I have bigger issues.
I'm more worried about being able to semi-reliably authenticate a device to the network so I don't have random Trunk ports lying around the network which I feel is a much bigger risk. Something is better then Nothing, and when your choice is to either stand up an entire PKI infrastructure to support automatic certificate enrollment and deployment..... or use a basic encryption layer and change to something more secure later (like Aruba 535 WAPs using ap1x and certificates deployed using Central :) )
Original Message:
Sent: Jul 21, 2022 11:55 AM
From: Herman Robers
Subject: Clearpass EAP-FAST with Cisco APs
I haven't seen too many customers deploying EAP-FAST because it has poor client support (need to install separate proprietry supplicant). With EAP-TLS you follow the industry standards and get the widest client support and proper public protocol security reviews. If you deploy EAP-FAST 'the easy way', with anonymous provisioning, you are vulnerable to man-in-the-middle attacks.
There are many Aruba customers running ClearPass with Cisco wired/wireless; just not running EAP-FAST (as far as I'm aware).
------------------------------
Herman Robers
------------------------
If you have urgent issues, always contact your Aruba partner, distributor, or Aruba TAC Support. Check https://www.arubanetworks.com/support-services/contact-support/ for how to contact Aruba TAC. Any opinions expressed here are solely my own and not necessarily that of Hewlett Packard Enterprise or Aruba Networks.
In case your problem is solved, please invest the time to post a follow-up with the information on how you solved it. Others can benefit from that.
Original Message:
Sent: Jul 20, 2022 10:27 AM
From: Tomas Backo
Subject: Clearpass EAP-FAST with Cisco APs
Hi Herman,
I will open TAC for this. I am a little bit surprised, that there isn't much about EAP-FAST and Cisco integration. At least for me it seems to be much easier that deploying certificates on Cisco WLC/APs and implement EAP-Peap or TLS.
thank you
Tomas
Original Message:
Sent: Jul 19, 2022 09:17 AM
From: Herman Robers
Subject: Clearpass EAP-FAST with Cisco APs
Tomas,
I see in TAC case-notes for an issue with EAP-FAST and the unexpected TLV that there is an issue in combination with Anyconnect, and Cisco TAC was able to fix it. In that case EAP-FAST worked with IOS/macOS. No further details on what exactly solved the issue.
Otherwise, best to open a TAC case with Aruba support to get the issue investigated.
------------------------------
Herman Robers
------------------------
If you have urgent issues, always contact your Aruba partner, distributor, or Aruba TAC Support. Check https://www.arubanetworks.com/support-services/contact-support/ for how to contact Aruba TAC. Any opinions expressed here are solely my own and not necessarily that of Hewlett Packard Enterprise or Aruba Networks.
In case your problem is solved, please invest the time to post a follow-up with the information on how you solved it. Others can benefit from that.
Original Message:
Sent: Jul 19, 2022 03:52 AM
From: Tomas Backo
Subject: Clearpass EAP-FAST with Cisco APs
Hi Michael,
sorry for reopening this old post. I am just wandering if you find the solution for your issue or it the TAC helped you somehow.
I run into pretty the same issue, with the same results.
User is authenticated successfully, but then there is a message about receiving unexpected TLV and session is rejected.
Clearpass on 6.9.11 and Cisco WLC 3504 on 8.10
Thanks a lot
Tomas
Original Message:
Sent: Nov 08, 2021 10:29 AM
From: Michael Höflmaier
Subject: Clearpass EAP-FAST with Cisco APs
Hi dear community-members,
I am currently desperately trying to get Cisco APs to authenticate against CPPM.
My setup:
Cisco AP9100 with EAP-FAST and User+PW
Clearpass 6.9.7
ISE
I didn't manage to authenticate the AP against CPPM with EAP-FAST.
In my desperation, I already tried to get the AP to authenticate against ISE, which worked just fine.
Error message on CP:
Error message on Cisco-AP:
Currently, I assume that CP and AP are calculating a different compound mac, but I can't really tell if this is the case.
Is there anybody who experianced this already?
Logs on CP:
- 2021-11-08 16:23:40,728 [Th 41 Req 1960 SessId R00000124-01-618940fc] INFO RadiusServer.Radius - rlm_service: Starting Service Categorization - 211:326:84-f1-47-b0-1f-e0
2021-11-08 16:23:40,736 [RequestHandler-1-0x7f22dffff700 r=psauto-1636099404-583 h=223 r=R00000124-01-618940fc] INFO Core.ServiceReqHandler - Service classification result = 0_5_WIRED_802.1X_Service_CiscoAP
2021-11-08 16:23:40,737 [Th 41 Req 1960 SessId R00000124-01-618940fc] INFO RadiusServer.Radius - Service Categorization time = 8 ms
2021-11-08 16:23:40,737 [Th 41 Req 1960 SessId R00000124-01-618940fc] INFO RadiusServer.Radius - rlm_service: The request has been categorized into service "0_5_WIRED_802.1X_Service_CiscoAP"
2021-11-08 16:23:40,737 [Th 41 Req 1960 SessId R00000124-01-618940fc] INFO RadiusServer.Radius - rlm_sql: searching for user pstahl in Local:localhost
2021-11-08 16:23:40,745 [Th 41 Req 1960 SessId R00000124-01-618940fc] INFO RadiusServer.Radius - rlm_sql: found user pstahl in Local:localhost
2021-11-08 16:23:40,745 [Th 41 Req 1960 SessId R00000124-01-618940fc] INFO RadiusServer.Radius - SQL User lookup time = 8 ms
2021-11-08 16:23:40,745 [Th 41 Req 1960 SessId R00000124-01-618940fc] INFO RadiusServer.Radius - rlm_eap_fast: Initiate
2021-11-08 16:23:40,745 [Th 41 Req 1960 SessId R00000124-01-618940fc] INFO RadiusServer.Radius - reqst_update_state: Access-Challenge 211:108:84-f1-47-b0-1f-e0:AIwAogDsAMGoBwAA6XAUh59SPZ61/t/ymCyLwQ==
2021-11-08 16:23:40,756 [Th 42 Req 1961 SessId R00000124-01-618940fc] INFO RadiusServer.Radius - rlm_service: The request was categorized into service "0_5_WIRED_802.1X_Service_CiscoAP" - 212:738:84-f1-47-b0-1f-e0
2021-11-08 16:23:40,756 [Th 42 Req 1961 SessId R00000124-01-618940fc] INFO RadiusServer.Radius - TLS_accept:error in SSLv3 read finished A
2021-11-08 16:23:40,757 [Th 42 Req 1961 SessId R00000124-01-618940fc] INFO RadiusServer.Radius - TLS_accept:error in SSLv3 read finished A
2021-11-08 16:23:40,757 [Th 42 Req 1961 SessId R00000124-01-618940fc] INFO RadiusServer.Radius - reqst_update_state: Access-Challenge 212:237:84-f1-47-b0-1f-e0:AOoA6QA9ABepBwAAYpwu3u9TJFOZJRqCjnqx4g==
2021-11-08 16:23:40,767 [Th 43 Req 1962 SessId R00000124-01-618940fc] INFO RadiusServer.Radius - rlm_service: The request was categorized into service "0_5_WIRED_802.1X_Service_CiscoAP" - 213:414:84-f1-47-b0-1f-e0
2021-11-08 16:23:40,767 [Th 43 Req 1962 SessId R00000124-01-618940fc] INFO RadiusServer.Radius - rlm_eap_fast: Session established.
2021-11-08 16:23:40,767 [Th 43 Req 1962 SessId R00000124-01-618940fc] INFO RadiusServer.Radius - reqst_update_state: Access-Challenge 213:130:84-f1-47-b0-1f-e0:AAwA3ABOAHOqBwAAJ4LGcQQbBlJdz9Lu+9KcEQ==
2021-11-08 16:23:40,777 [Th 44 Req 1963 SessId R00000124-01-618940fc] INFO RadiusServer.Radius - rlm_service: The request was categorized into service "0_5_WIRED_802.1X_Service_CiscoAP" - 214:407:84-f1-47-b0-1f-e0
2021-11-08 16:23:40,778 [Th 44 Req 1963 SessId R00000124-01-618940fc] INFO RadiusServer.Radius - rlm_eap_mschapv2: Issuing Challenge
2021-11-08 16:23:40,778 [Th 44 Req 1963 SessId R00000124-01-618940fc] INFO RadiusServer.Radius - reqst_update_state: Access-Challenge 214:157:84-f1-47-b0-1f-e0:AMQAQgB3ALarBwAA9sCtTrXhMav/nyo6THJNTQ==
2021-11-08 16:23:40,789 [Th 41 Req 1964 SessId R00000124-01-618940fc] INFO RadiusServer.Radius - rlm_service: The request was categorized into service "0_5_WIRED_802.1X_Service_CiscoAP" - 215:461:84-f1-47-b0-1f-e0
2021-11-08 16:23:40,789 [Th 41 Req 1964 SessId R00000124-01-618940fc] INFO RadiusServer.Radius - rlm_service: The request was categorized into service "0_5_WIRED_802.1X_Service_CiscoAP" - 172:0:84-f1-47-b0-1f-e0
2021-11-08 16:23:40,789 [Th 41 Req 1964 SessId R00000124-01-618940fc] INFO RadiusServer.Radius - rlm_eap_mschapv2: Received MSCHAPv2 Response from client
2021-11-08 16:23:40,789 [Th 41 Req 1964 SessId R00000124-01-618940fc] INFO RadiusServer.Radius - rlm_mschap: MSCHAPv2 username used for challenge computation pstahl
2021-11-08 16:23:40,789 [Th 41 Req 1964 SessId R00000124-01-618940fc] INFO RadiusServer.Radius - MS-Chap User Authentication time = 0 ms
2021-11-08 16:23:40,790 [Th 41 Req 1964 SessId R00000124-01-618940fc] INFO RadiusServer.Radius - rlm_eap_mschapv2: Sending MSCHAPv2 Success reply
2021-11-08 16:23:40,790 [Th 41 Req 1964 SessId R00000124-01-618940fc] INFO RadiusServer.Radius - reqst_update_state: Access-Challenge 215:176:84-f1-47-b0-1f-e0:ALsA9QAZAIKsBwAAIudEdTsIwRzgkiHNBjA8Fw==
2021-11-08 16:23:40,800 [Th 42 Req 1965 SessId R00000124-01-618940fc] INFO RadiusServer.Radius - rlm_service: The request was categorized into service "0_5_WIRED_802.1X_Service_CiscoAP" - 216:402:84-f1-47-b0-1f-e0
2021-11-08 16:23:40,800 [Th 42 Req 1965 SessId R00000124-01-618940fc] INFO RadiusServer.Radius - rlm_service: The request was categorized into service "0_5_WIRED_802.1X_Service_CiscoAP" - 173:0:84-f1-47-b0-1f-e0
2021-11-08 16:23:40,801 [Th 42 Req 1965 SessId R00000124-01-618940fc] INFO RadiusServer.Radius - rlm_eap_mschapv2: Received MSCHAPv2 Success from client
2021-11-08 16:23:40,801 [Th 42 Req 1965 SessId R00000124-01-618940fc] INFO RadiusServer.Radius - rlm_policy: Bypassing Policy Evaluation.
2021-11-08 16:23:40,801 [Th 42 Req 1965 SessId R00000124-01-618940fc] INFO RadiusServer.Radius - reqst_update_state: Access-Challenge 216:187:84-f1-47-b0-1f-e0:ANgAhwDjAHqtBwAAnd66ITCjeaDiZYq+FgLShA==
2021-11-08 16:23:40,811 [Th 43 Req 1966 SessId R00000124-01-618940fc] INFO RadiusServer.Radius - rlm_service: The request was categorized into service "0_5_WIRED_802.1X_Service_CiscoAP" - 217:404:84-f1-47-b0-1f-e0
2021-11-08 16:23:40,812 [Th 43 Req 1966 SessId R00000124-01-618940fc] INFO RadiusServer.Radius - rlm_policy: Starting Policy Evaluation.
2021-11-08 16:23:40,816 [RequestHandler-1-0x7f22dffff700 r=psauto-1636099404-584 h=239 r=R00000124-01-618940fc] INFO Common.EndpointTable - Returning EndpointSPtr for macAddr 84f147b01fe0
2021-11-08 16:23:40,816 [RequestHandler-1-0x7f22dffff700 r=psauto-1636099404-584 h=239 r=R00000124-01-618940fc] INFO Common.TagDefinitionCacheTable - No InstanceTagDefCacheMap found for instance id = 3022 entity id = 29
2021-11-08 16:23:40,816 [RequestHandler-1-0x7f22dffff700 r=psauto-1636099404-584 h=239 r=R00000124-01-618940fc] INFO Common.TagDefinitionCacheTable - Building the TagDefMapTable for NAD instance=3022
2021-11-08 16:23:40,816 [RequestHandler-1-0x7f22dffff700 r=psauto-1636099404-584 h=239 r=R00000124-01-618940fc] INFO Common.TagDefinitionCacheTable - Built 0 tag(s) for NAD instanceId=3022|entityId=29
2021-11-08 16:23:40,816 [RequestHandler-1-0x7f22dffff700 r=psauto-1636099404-584 h=239 r=R00000124-01-618940fc] INFO TAT.TagAttrHolderBuilder - No tags built for instanceId=3022|entity=Device
2021-11-08 16:23:40,816 [RequestHandler-1-0x7f22dffff700 r=psauto-1636099404-584 h=239 r=R00000124-01-618940fc] INFO TAT.AluTagAttrHolderBuilder - buildAttrHolder: Tags cannot be built for instanceId=0 (NULL AuthLocalUser)
2021-11-08 16:23:40,816 [RequestHandler-1-0x7f22dffff700 r=psauto-1636099404-584 h=239 r=R00000124-01-618940fc] INFO TAT.GuTagAttrHolderBuilder - buildAttrHolder: Tags cannot be built for instanceId=0 (NULL GuestUser)
2021-11-08 16:23:40,816 [RequestHandler-1-0x7f22dffff700 r=psauto-1636099404-584 h=239 r=R00000124-01-618940fc] INFO Common.TagDefinitionCacheTable - No InstanceTagDefCacheMap found for instance id = 3268 entity id = 72
2021-11-08 16:23:40,816 [RequestHandler-1-0x7f22dffff700 r=psauto-1636099404-584 h=239 r=R00000124-01-618940fc] INFO Common.TagDefinitionCacheTable - Building the TagDefMapTable for Endpoint instance=3268
2021-11-08 16:23:40,816 [RequestHandler-1-0x7f22dffff700 r=psauto-1636099404-584 h=239 r=R00000124-01-618940fc] INFO Common.TagDefinitionCacheTable - Built 0 tag(s) for instanceId=3268|entityId=72|entityName=Endpoint
2021-11-08 16:23:40,816 [RequestHandler-1-0x7f22dffff700 r=psauto-1636099404-584 h=239 r=R00000124-01-618940fc] INFO TAT.TagAttrHolderBuilder - No tags built for instanceId=3268|entity=Endpoint
2021-11-08 16:23:40,816 [RequestHandler-1-0x7f22dffff700 r=psauto-1636099404-584 h=239 r=R00000124-01-618940fc] INFO TAT.OnboardTagAttrHolderBuilder - buildAttrHolder: Tags cannot be built for instanceId=0 (NULL Onboard Device User)
2021-11-08 16:23:40,817 [RequestHandler-1-0x7f22dffff700 h=5502 c=R00000124-01-618940fc] INFO Core.PETaskScheduler - *** PE_TASK_SCHEDULE_RADIUS Started ***
2021-11-08 16:23:40,817 [RequestHandler-1-0x7f22dffff700 h=5502 c=R00000124-01-618940fc] INFO Core.PETaskScheduler - ** Starting PETaskAuthSourceRestriction **
2021-11-08 16:23:40,817 [RequestHandler-1-0x7f22dffff700 h=5502 c=R00000124-01-618940fc] INFO Core.PETaskScheduler - ** Starting PETaskRoleMapping **
2021-11-08 16:23:40,818 [RequestHandler-1-0x7f22dffff700 r=R00000124-01-618940fc h=5502 c=R00000124-01-618940fc] INFO Core.PETaskScheduler - ** Completed PETaskAuthSourceRestriction **
2021-11-08 16:23:40,818 [RequestHandler-1-0x7f22dffff700 h=5504 c=R00000124-01-618940fc] INFO Core.PETaskRoleMapping - Roles:
2021-11-08 16:23:40,818 [RequestHandler-1-0x7f22dffff700 r=R00000124-01-618940fc h=5502 c=R00000124-01-618940fc] INFO Core.PETaskScheduler - ** Completed PETaskRoleMapping **
2021-11-08 16:23:40,818 [RequestHandler-1-0x7f22dffff700 r=R00000124-01-618940fc h=5502 c=R00000124-01-618940fc] INFO Core.PETaskScheduler - ** Starting PETaskPolicyResult **
2021-11-08 16:23:40,818 [RequestHandler-1-0x7f22dffff700 r=R00000124-01-618940fc h=5502 c=R00000124-01-618940fc] INFO Core.PETaskScheduler - ** Completed PETaskPolicyResult **
2021-11-08 16:23:40,819 [RequestHandler-1-0x7f22dffff700 r=R00000124-01-618940fc h=5502 c=R00000124-01-618940fc] INFO Core.PETaskScheduler - ** Starting PETaskEnforcement **
2021-11-08 16:23:40,819 [RequestHandler-1-0x7f22dffff700 h=5507 c=R00000124-01-618940fc] INFO Core.PETaskEnforcement - EnfProfiles: Allow Access Profile]
2021-11-08 16:23:40,820 [RequestHandler-1-0x7f22dffff700 r=R00000124-01-618940fc h=5502 c=R00000124-01-618940fc] INFO Core.PETaskScheduler - ** Completed PETaskEnforcement **
2021-11-08 16:23:40,820 [RequestHandler-1-0x7f22dffff700 r=R00000124-01-618940fc h=5502 c=R00000124-01-618940fc] INFO Core.PETaskScheduler - ** Starting PETaskRadiusEnfProfileBuilder **
2021-11-08 16:23:40,820 [RequestHandler-1-0x7f22dffff700 r=R00000124-01-618940fc h=5502 c=R00000124-01-618940fc] INFO Core.PETaskScheduler - ** Starting PETaskRadiusCoAEnfProfileBuilder **
2021-11-08 16:23:40,820 [RequestHandler-1-0x7f22dffff700 r=R00000124-01-618940fc h=5502 c=R00000124-01-618940fc] INFO Core.PETaskScheduler - ** Starting PETaskAppEnfProfileBuilder **
2021-11-08 16:23:40,820 [RequestHandler-1-0x7f22dffff700 r=R00000124-01-618940fc h=5502 c=R00000124-01-618940fc] INFO Core.PETaskScheduler - ** Starting PETaskAgentEnfProfileBuilder **
2021-11-08 16:23:40,820 [RequestHandler-1-0x7f22dffff700 r=R00000124-01-618940fc h=5502 c=R00000124-01-618940fc] INFO Core.PETaskScheduler - ** Starting PETaskPostAuthEnfProfileBuilder **
2021-11-08 16:23:40,820 [RequestHandler-1-0x7f22dffff700 r=R00000124-01-618940fc h=5502 c=R00000124-01-618940fc] INFO Core.PETaskScheduler - ** Starting PETaskGenericEnfProfileBuilder **
2021-11-08 16:23:40,820 [RequestHandler-1-0x7f22dffff700 h=5513 c=R00000124-01-618940fc] INFO Core.PETaskGenericEnfProfileBuilder - getApplicableProfiles: No App enforcement (Generic) profiles applicable for this device
2021-11-08 16:23:40,821 [RequestHandler-1-0x7f22dffff700 h=5508 c=R00000124-01-618940fc] INFO Core.PETaskRadiusEnfProfileBuilder - EnfProfileAction=ACCEPT
2021-11-08 16:23:40,821 [RequestHandler-1-0x7f22dffff700 h=5508 c=R00000124-01-618940fc] INFO Core.PETaskRadiusEnfProfileBuilder - Radius enfProfiles used: Allow Access Profile]
2021-11-08 16:23:40,821 [RequestHandler-1-0x7f22dffff700 h=5508 c=R00000124-01-618940fc] INFO Core.EnfProfileComputer - getFinalSessionTimeout: sessionTimeout = 0
2021-11-08 16:23:40,821 [RequestHandler-1-0x7f22dffff700 r=R00000124-01-618940fc h=5502 c=R00000124-01-618940fc] INFO Core.PETaskScheduler - ** Completed PETaskGenericEnfProfileBuilder **
2021-11-08 16:23:40,821 [RequestHandler-1-0x7f22dffff700 r=R00000124-01-618940fc h=5502 c=R00000124-01-618940fc] INFO Core.PETaskScheduler - ** Completed PETaskAgentEnfProfileBuilder **
2021-11-08 16:23:40,822 [RequestHandler-1-0x7f22dffff700 r=R00000124-01-618940fc h=5502 c=R00000124-01-618940fc] INFO Core.PETaskScheduler - ** Completed PETaskAppEnfProfileBuilder **
2021-11-08 16:23:40,822 [RequestHandler-1-0x7f22dffff700 r=R00000124-01-618940fc h=5502 c=R00000124-01-618940fc] INFO Core.PETaskScheduler - ** Starting PETaskCliEnforcement **
2021-11-08 16:23:40,822 [RequestHandler-1-0x7f22dffff700 h=5514 c=R00000124-01-618940fc] INFO Core.PETaskCliEnforcement - startHandler: No commands for CLI enforcement
2021-11-08 16:23:40,822 [RequestHandler-1-0x7f22dffff700 r=R00000124-01-618940fc h=5502 c=R00000124-01-618940fc] INFO Core.PETaskScheduler - ** Completed PETaskRadiusEnfProfileBuilder **
2021-11-08 16:23:40,822 [RequestHandler-1-0x7f22dffff700 r=R00000124-01-618940fc h=5512 c=R00000124-01-618940fc] WARN Core.PETaskPostAuthEnfProfileBuilder - handleHttpResponseEv: Fetching Radius attributes from battery failed, errMsg=
2021-11-08 16:23:40,822 [RequestHandler-1-0x7f22dffff700 r=R00000124-01-618940fc h=5512 c=R00000124-01-618940fc] INFO Core.PETaskPostAuthEnfProfileBuilder - getApplicableProfiles: No Post auth enforcement profiles applicable for this device
2021-11-08 16:23:40,822 [RequestHandler-1-0x7f22dffff700 r=R00000124-01-618940fc h=5502 c=R00000124-01-618940fc] INFO Core.PETaskScheduler - ** Completed PETaskCliEnforcement **
2021-11-08 16:23:40,822 [RequestHandler-1-0x7f22dffff700 r=R00000124-01-618940fc h=5502 c=R00000124-01-618940fc] INFO Core.PETaskScheduler - ** Completed PETaskPostAuthEnfProfileBuilder **
2021-11-08 16:23:40,843 [RequestHandler-1-0x7f22dffff700 r=R00000124-01-618940fc h=5509 c=R00000124-01-618940fc] WARN Core.PETaskRadiusCoAEnfProfileBuilder - handleHttpResponseEv: Fetching Radius attributes from battery failed, errMsg=
2021-11-08 16:23:40,843 [RequestHandler-1-0x7f22dffff700 r=R00000124-01-618940fc h=5502 c=R00000124-01-618940fc] INFO Core.PETaskScheduler - ** Completed PETaskRadiusCoAEnfProfileBuilder **
2021-11-08 16:23:40,843 [RequestHandler-1-0x7f22dffff700 r=R00000124-01-618940fc h=5502 c=R00000124-01-618940fc] INFO Core.PETaskScheduler - ** Starting PETaskAuthStatusInfo **
2021-11-08 16:23:40,843 [RequestHandler-1-0x7f22dffff700 r=R00000124-01-618940fc h=5502 c=R00000124-01-618940fc] INFO Core.PETaskScheduler - ** Starting PETaskOutputPolicyRes **
2021-11-08 16:23:40,843 [RequestHandler-1-0x7f22dffff700 r=R00000124-01-618940fc h=5502 c=R00000124-01-618940fc] INFO Core.PETaskScheduler - ** Starting PETaskSessionLog **
2021-11-08 16:23:40,849 [RequestHandler-1-0x7f22dffff700 h=5516 c=R00000124-01-618940fc] INFO Core.XpipPolicyResHandler - populateResponseTlv: PETaskPostureOutput does not exist. Skip sending posture VAFs
2021-11-08 16:23:40,849 [RequestHandler-1-0x7f22dffff700 h=5516 c=R00000124-01-618940fc] INFO Core.PolicyResCollector - getSohr: Failed to generate Sohr
2021-11-08 16:23:40,849 [RequestHandler-1-0x7f22dffff700 h=5515 c=R00000124-01-618940fc] INFO Core.PolicyResCollector - getSohr: Failed to generate Sohr
2021-11-08 16:23:40,849 [RequestHandler-1-0x7f22dffff700 r=R00000124-01-618940fc h=5502 c=R00000124-01-618940fc] INFO Core.PETaskScheduler - ** Completed PETaskSessionLog **
2021-11-08 16:23:40,850 [Th 43 Req 1966 SessId R00000124-01-618940fc] INFO RadiusServer.Radius - Policy Evaluation time = 38 ms
2021-11-08 16:23:40,850 [Th 43 Req 1966 SessId R00000124-01-618940fc] INFO RadiusServer.Radius - rlm_policy: Received Accept Enforcement Profile
2021-11-08 16:23:40,850 [Th 43 Req 1966 SessId R00000124-01-618940fc] INFO RadiusServer.Radius - rlm_policy: Policy Server reply does not contain Posture-Validation-Response
2021-11-08 16:23:40,850 [Th 43 Req 1966 SessId R00000124-01-618940fc] INFO RadiusServer.Radius - Request processing time = 122 ms
2021-11-08 16:23:40,850 [RequestHandler-1-0x7f22dffff700 r=R00000124-01-618940fc h=5502 c=R00000124-01-618940fc] INFO Core.PETaskScheduler - ** Completed PETaskOutputPolicyRes **
2021-11-08 16:23:40,850 [RequestHandler-1-0x7f22dffff700 r=R00000124-01-618940fc h=5502 c=R00000124-01-618940fc] INFO Core.PETaskScheduler - ** Completed PETaskAuthStatusInfo **
2021-11-08 16:23:40,850 [RequestHandler-1-0x7f22dffff700 r=R00000124-01-618940fc h=5502 c=R00000124-01-618940fc] INFO Core.PETaskScheduler - *** PE_TASK_SCHEDULE_RADIUS Completed ***
------------------------------
Michael
------------------------------