Request log details for session: R00001e9f-01-660bdb39 Time Message 2024-04-02 13:17:29,297 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Processing the authorize section of radiusd.conf 2024-04-02 13:17:29,297 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcall: entering group authorize for request 545908 2024-04-02 13:17:29,297 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcallauthorize]: module "dacl" returns noop for request 545908 2024-04-02 13:17:29,297 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_service: The request does not have Service-State attribute 2024-04-02 13:17:29,297 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] INFO RadiusServer.Radius - rlm_service: Starting Service Categorization - 31:303:34-8A-12-C7-A1-34 2024-04-02 13:17:29,297 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_service: service_get_polsvr_conn: Checking Id: 0 2024-04-02 13:17:29,297 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_service: service_get_polsvr_conn: Got Id: 0, handle: 0xed28e0 2024-04-02 13:17:29,297 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_service: add req-packet attributes 2024-04-02 13:17:29,297 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - User-Name = "MEDOA-WH-20" 2024-04-02 13:17:29,297 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Service-Type = Framed-User 2024-04-02 13:17:29,297 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Cisco-AVPair = "service-type=Framed" 2024-04-02 13:17:29,297 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Framed-MTU = 1468 2024-04-02 13:17:29,297 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - EAP-Message = 0x02020010014d45444f412d57482d3230 2024-04-02 13:17:29,297 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Message-Authenticator = 0x0f3f4e54bd92791874f4b68f3bb06c96 2024-04-02 13:17:29,297 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Cisco-AVPair = "audit-session-id=0CC8020A000080F09E3B65BA" 2024-04-02 13:17:29,298 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Cisco-AVPair = "method=dot1x" 2024-04-02 13:17:29,298 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Cisco-AVPair = "client-iif-id=338979414" 2024-04-02 13:17:29,298 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - NAS-IP-Address = 10.2.200.12 2024-04-02 13:17:29,298 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - NAS-Port-Id = "GigabitEthernet4/0/26" 2024-04-02 13:17:29,298 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - NAS-Port-Type = Ethernet 2024-04-02 13:17:29,298 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - NAS-Port = 50426 2024-04-02 13:17:29,298 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Calling-Station-Id = "34-8A-12-C7-A1-34" 2024-04-02 13:17:29,298 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - NAS-Identifier = "Pegasus_FL01" 2024-04-02 13:17:29,298 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Called-Station-Id = "74-88-BB-F4-1D-9A" 2024-04-02 13:17:29,298 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_service: add config attributes 2024-04-02 13:17:29,298 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Session-Id = "R00001e9f-01-660bdb39" 2024-04-02 13:17:29,298 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_service: add connection attributes 2024-04-02 13:17:29,298 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_service: Adding Connection:Src-IP-Address=10.2.200.12 2024-04-02 13:17:29,298 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_service: Adding Connection:NAD-IP-Address=10.2.200.12 2024-04-02 13:17:29,298 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_service: Adding Connection:Dest-IP-Address=10.2.0.60 2024-04-02 13:17:29,305 [RequestHandler-1-0x7f2883fff700 r=psauto-1711690116-87593 h=223 r=R00001e9f-01-660bdb39] INFO Core.ServiceReqHandler - Service classification result = MEDO-AP Wired Aruba Access Point DYN VLAN 802.1X 2024-04-02 13:17:29,306 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG StatsDClient.StatsClient - Formatted StatsD data=default.cynac1.radius.serviceeval.time:8|ms 2024-04-02 13:17:29,306 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG StatsDClient.StatsClient - Sending StatsD request=default.cynac1.radius.serviceeval.time:8|ms 2024-04-02 13:17:29,306 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] INFO RadiusServer.Radius - Service Categorization time = 8 ms 2024-04-02 13:17:29,306 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_service: Policy Server reply does not contain Requested-Posture-Credentials 2024-04-02 13:17:29,306 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_service: service_release_polsvr_conn: Release Id: 0, handle: 0xed28e0 2024-04-02 13:17:29,306 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] INFO RadiusServer.Radius - rlm_service: The request has been categorized into service "MEDO-AP Wired Aruba Access Point DYN VLAN 802.1X" 2024-04-02 13:17:29,306 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_service: svcreq_list_add Service-State = 0x001100390032001b74540800112a924302cd425abfb1255f7fe0288d, Session-Id = "R00001e9f-01-660bdb39" 2024-04-02 13:17:29,306 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcallauthorize]: module "service" returns ok for request 545908 2024-04-02 13:17:29,306 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcall: leaving group authorize (returns ok) for request 545908 2024-04-02 13:17:29,306 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Found Autz-Type svc_MEDO-AP Wired Aruba Access Point DYN VLAN 802.1X_3099 2024-04-02 13:17:29,306 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Processing the authorize section of radiusd.conf 2024-04-02 13:17:29,306 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcall: entering group svc_MEDO-AP Wired Aruba Access Point DYN VLAN 802.1X_3099 for request 545908 2024-04-02 13:17:29,306 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcall: entering group for request 545908 2024-04-02 13:17:29,306 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] INFO RadiusServer.Radius - rlm_sql: searching for user MEDOA-WH-20 in Local:localhost 2024-04-02 13:17:29,306 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - radius_xlat: Running registered xlat function of module Connection for string 'Client-Mac-Address-NoDelim' 2024-04-02 13:17:29,306 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - radius_xlat: 'SELECT mac_address AS User_Password FROM tips_endpoints WHERE mac_address = LOWER('348A12C7A134') AND status = 'Known'' 2024-04-02 13:17:29,306 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_sql (authsrc_4): Reserving sql socket id: 31 2024-04-02 13:17:29,307 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_sql: The number of fields: 1. 2024-04-02 13:17:29,307 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_sql: Coulmn label user_password 2024-04-02 13:17:29,307 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_sql (authsrc_4): User MEDOA-WH-20 found 2024-04-02 13:17:29,307 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_sql (authsrc_4): Released sql socket id: 31 2024-04-02 13:17:29,307 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] INFO RadiusServer.Radius - rlm_sql: found user MEDOA-WH-20 in Local:localhost 2024-04-02 13:17:29,307 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_sql: Adding Persisted-User-Name MEDOA-WH-20 to persistent items 2024-04-02 13:17:29,307 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG StatsDClient.StatsClient - Formatted StatsD data=default.cynac1.radius.auth._Endpoints_Repository_.lookup-time:1|ms 2024-04-02 13:17:29,307 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG StatsDClient.StatsClient - Sending StatsD request=default.cynac1.radius.auth._Endpoints_Repository_.lookup-time:1|ms 2024-04-02 13:17:29,307 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] INFO RadiusServer.Radius - SQL User lookup time = 1 ms 2024-04-02 13:17:29,307 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG StatsDClient.StatsClient - Formatted StatsD data=default.cynac1.radius.auth.time:1|ms 2024-04-02 13:17:29,307 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG StatsDClient.StatsClient - Sending StatsD request=default.cynac1.radius.auth.time:1|ms 2024-04-02 13:17:29,307 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcallauthorize]: module "authsrc_4" returns ok for request 545908 2024-04-02 13:17:29,307 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcall: leaving group (returns ok) for request 545908 2024-04-02 13:17:29,307 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap: Deleting Proxy-To-Realm and Post-Proxy-Type attributes 2024-04-02 13:17:29,307 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap: EAP packet type response id 2 length 16 2024-04-02 13:17:29,307 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap: No EAP Start, assuming it's an on-going EAP conversation 2024-04-02 13:17:29,307 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcallauthorize]: module "svc_3099_eap" returns updated for request 545908 2024-04-02 13:17:29,307 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_auth_check: Allowed authentication methods: svc_3099_eap 2024-04-02 13:17:29,307 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - radius: No MS Identity VP 2024-04-02 13:17:29,307 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_auth_check: allowed Authentication method svc_3099_eap set. 2024-04-02 13:17:29,307 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcallauthorize]: module "svc_3099_auth_check" returns ok for request 545908 2024-04-02 13:17:29,307 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcall: leaving group svc_MEDO-AP Wired Aruba Access Point DYN VLAN 802.1X_3099 (returns updated) for request 545908 2024-04-02 13:17:29,307 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rad_check_password: Found Auth-Type svc_3099_eap 2024-04-02 13:17:29,307 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - auth: type "svc_3099_eap" 2024-04-02 13:17:29,307 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Processing the authenticate section of radiusd.conf 2024-04-02 13:17:29,307 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcall: entering group svc_3099_eap for request 545908 2024-04-02 13:17:29,307 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap: EAP Identity 2024-04-02 13:17:29,307 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap: processing type tls instance Medo EAP TLS without Authorization 2024-04-02 13:17:29,307 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] INFO RadiusServer.Radius - rlm_eap_tls: Initiate 2024-04-02 13:17:29,307 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap_tls: Requiring client certificate 2024-04-02 13:17:29,307 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap_tls: Start returned 1 2024-04-02 13:17:29,307 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap: eap_compose returned 3 2024-04-02 13:17:29,307 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap: eap_list_add EAP-State = 0x0011002e005b004374540800bf8ad7d5368706b0 2024-04-02 13:17:29,307 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcallauthenticate]: module "svc_3099_eap" returns handled for request 545908 2024-04-02 13:17:29,307 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcall: leaving group svc_3099_eap (returns handled) for request 545908 2024-04-02 13:17:29,307 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - The request contains following state_items 2024-04-02 13:17:29,307 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Service-State = 0x001100390032001b74540800112a924302cd425abfb1255f7fe0288d 2024-04-02 13:17:29,307 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - EAP-State = 0x0011002e005b004374540800bf8ad7d5368706b0 2024-04-02 13:17:29,307 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - The request contains following session_id 2024-04-02 13:17:29,307 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Session-Id = "R00001e9f-01-660bdb39" 2024-04-02 13:17:29,307 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - The request contains following session messages 2024-04-02 13:17:29,307 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - The request contains following persistent config items 2024-04-02 13:17:29,307 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - User-Password = 2024-04-02 13:17:29,307 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Persisted-User-Name = "MEDOA-WH-20" 2024-04-02 13:17:29,307 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Authentication-Source = "Local:localhost" 2024-04-02 13:17:29,307 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Authentication-Source-Name = "Endpoints Repository]" 2024-04-02 13:17:29,307 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Authentication-Source-Id = 4 2024-04-02 13:17:29,307 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Policy Evaluation Status: 0, Request Status: 0, Error Code: 0 2024-04-02 13:17:29,307 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - reqst_node_alloc: allocating pkt info - 0xb0047210, pkt info size 16 2024-04-02 13:17:29,307 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - reqst_node_alloc: updated pkt info - pkt # 0 2024-04-02 13:17:29,307 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Sending Access-Challenge of id 31 to 10.2.200.12 port 63420 2024-04-02 13:17:29,307 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - EAP-Message = 0x010300060d20 2024-04-02 13:17:29,307 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Message-Authenticator = 0x00000000000000000000000000000000 2024-04-02 13:17:29,307 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - State = 0x414d67413051434d414d563056416741587a3951736e6941455a304463654d626f3537772f773d3d 2024-04-02 13:17:29,307 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - reqst_update_state node pkt info ptr 0xb0047210, req cur pkt # 0, node cur pkt # 0 2024-04-02 13:17:29,307 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] INFO RadiusServer.Radius - reqst_update_state: Access-Challenge 31:88:34-8A-12-C7-A1-34:AMgA0QCMAMV0VAgAXz9QsniAEZ0DceMbo57w/w== 2024-04-02 13:17:29,307 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Finished request 545908 2024-04-02 13:17:29,307 [Th 315 Req 545908 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Going to the next request 2024-04-02 13:17:29,318 [Th 313 Req 545909] DEBUG RadiusServer.Radius - Session-Id = "R00001e9f-01-660bdb39" 2024-04-02 13:17:29,318 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Processing the authorize section of radiusd.conf 2024-04-02 13:17:29,318 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcall: entering group authorize for request 545909 2024-04-02 13:17:29,318 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcallauthorize]: module "dacl" returns noop for request 545909 2024-04-02 13:17:29,318 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_service: The request has Service-State attribute 2024-04-02 13:17:29,318 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_service: svcreq_list_find Service-State = 0x001100390032001b74540800112a924302cd425abfb1255f7fe0288d, Session-Id = "R00001e9f-01-660bdb39" 2024-04-02 13:17:29,318 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_service: Request found, released from the list 2024-04-02 13:17:29,318 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] INFO RadiusServer.Radius - rlm_service: The request was categorized into service "MEDO-AP Wired Aruba Access Point DYN VLAN 802.1X" - 39:419:34-8A-12-C7-A1-34 2024-04-02 13:17:29,318 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_service: svcreq_list_add Service-State = 0x00d9002a00b800d275540800619bf19f31a558be985c7d8711a38ce2, Session-Id = "R00001e9f-01-660bdb39" 2024-04-02 13:17:29,318 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcallauthorize]: module "service" returns ok for request 545909 2024-04-02 13:17:29,318 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcall: leaving group authorize (returns ok) for request 545909 2024-04-02 13:17:29,318 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Found Autz-Type svc_MEDO-AP Wired Aruba Access Point DYN VLAN 802.1X_3099 2024-04-02 13:17:29,318 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Processing the authorize section of radiusd.conf 2024-04-02 13:17:29,318 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcall: entering group svc_MEDO-AP Wired Aruba Access Point DYN VLAN 802.1X_3099 for request 545909 2024-04-02 13:17:29,318 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcall: entering group for request 545909 2024-04-02 13:17:29,318 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_sql (authsrc_4): Request contains authsrc items, returning 2024-04-02 13:17:29,318 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcallauthorize]: module "authsrc_4" returns ok for request 545909 2024-04-02 13:17:29,318 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcall: leaving group (returns ok) for request 545909 2024-04-02 13:17:29,318 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap: Deleting Proxy-To-Realm and Post-Proxy-Type attributes 2024-04-02 13:17:29,318 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap: EAP packet type response id 3 length 90 2024-04-02 13:17:29,318 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap: No EAP Start, assuming it's an on-going EAP conversation 2024-04-02 13:17:29,318 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcallauthorize]: module "svc_3099_eap" returns updated for request 545909 2024-04-02 13:17:29,318 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_auth_check: Allowed authentication methods: svc_3099_eap 2024-04-02 13:17:29,318 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - radius: No MS Identity VP 2024-04-02 13:17:29,318 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_auth_check: allowed Authentication method svc_3099_eap set. 2024-04-02 13:17:29,318 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcallauthorize]: module "svc_3099_auth_check" returns ok for request 545909 2024-04-02 13:17:29,318 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcall: leaving group svc_MEDO-AP Wired Aruba Access Point DYN VLAN 802.1X_3099 (returns updated) for request 545909 2024-04-02 13:17:29,318 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rad_check_password: Found Auth-Type svc_3099_eap 2024-04-02 13:17:29,318 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - auth: type "svc_3099_eap" 2024-04-02 13:17:29,318 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Processing the authenticate section of radiusd.conf 2024-04-02 13:17:29,318 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcall: entering group svc_3099_eap for request 545909 2024-04-02 13:17:29,318 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap: eaplist_find EAP-State = 0x0011002e005b004374540800bf8ad7d5368706b0 2024-04-02 13:17:29,318 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap_tls: SSL ex data at index 1 - (nil) 2024-04-02 13:17:29,319 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap: Request found, released from the list 2024-04-02 13:17:29,319 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap: EAP/tls 2024-04-02 13:17:29,319 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap: processing type tls instance Medo EAP TLS without Authorization 2024-04-02 13:17:29,319 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap_tls: Authenticate 2024-04-02 13:17:29,319 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap_tls: Authorization is not mandatory 2024-04-02 13:17:29,319 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap_tls: processing TLS 2024-04-02 13:17:29,319 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap_tls: Server version 0 Peer Version 0 Choosing 0 2024-04-02 13:17:29,319 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - eaptls_verify returned 7 2024-04-02 13:17:29,319 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap_tls: Done initial handshake 2024-04-02 13:17:29,319 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap_tls: TLS packet length 89 flags 00 2024-04-02 13:17:29,319 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - (other): before SSL initialization 2024-04-02 13:17:29,319 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - TLS_accept: before SSL initialization 2024-04-02 13:17:29,319 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Ignoring cbtls_msg call with pseudo content type 256, version 0 2024-04-02 13:17:29,319 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - TLS_accept: before SSL initialization 2024-04-02 13:17:29,319 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap_tls: <<< Unknown TLS version length 004f] 2024-04-02 13:17:29,319 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - TLS_accept: SSLv3/TLS read client hello 2024-04-02 13:17:29,319 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Ignoring cbtls_msg call with pseudo content type 256, version 0 2024-04-02 13:17:29,319 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap_tls: >>> TLS 1.2 Handshake length 002a], ServerHello 2024-04-02 13:17:29,319 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - TLS_accept: SSLv3/TLS write server hello 2024-04-02 13:17:29,319 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Ignoring cbtls_msg call with pseudo content type 256, version 0 2024-04-02 13:17:29,319 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap_tls: >>> TLS 1.2 Handshake length 03e1], Certificate 2024-04-02 13:17:29,319 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - TLS_accept: SSLv3/TLS write certificate 2024-04-02 13:17:29,319 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Ignoring cbtls_msg call with pseudo content type 256, version 0 2024-04-02 13:17:29,319 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap_tls: >>> TLS 1.2 Handshake length 0d23], CertificateRequest 2024-04-02 13:17:29,319 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - TLS_accept: SSLv3/TLS write certificate request 2024-04-02 13:17:29,319 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Ignoring cbtls_msg call with pseudo content type 256, version 0 2024-04-02 13:17:29,319 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap_tls: EAP-TLS-Version =1.2 2024-04-02 13:17:29,319 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap_tls: >>> TLS 1.2 Handshake length 0004], ServerHelloDone 2024-04-02 13:17:29,319 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - TLS_accept: SSLv3/TLS write server done 2024-04-02 13:17:29,319 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] INFO RadiusServer.Radius - TLS_accept:error in SSLv3/TLS write server done 2024-04-02 13:17:29,319 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - In SSL Handshake Phase 2024-04-02 13:17:29,319 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - In SSL Accept mode 2024-04-02 13:17:29,319 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - eaptls_process returned 13 2024-04-02 13:17:29,319 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap: eap_compose returned 3 2024-04-02 13:17:29,319 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap: eap_list_add EAP-State = 0x0023006d00d600d075540800b5c21c6681164fd3 2024-04-02 13:17:29,319 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcallauthenticate]: module "svc_3099_eap" returns handled for request 545909 2024-04-02 13:17:29,319 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcall: leaving group svc_3099_eap (returns handled) for request 545909 2024-04-02 13:17:29,319 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - The request contains following state_items 2024-04-02 13:17:29,319 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Service-State = 0x00d9002a00b800d275540800619bf19f31a558be985c7d8711a38ce2 2024-04-02 13:17:29,319 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - EAP-State = 0x0023006d00d600d075540800b5c21c6681164fd3 2024-04-02 13:17:29,319 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - The request contains following session_id 2024-04-02 13:17:29,319 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Session-Id = "R00001e9f-01-660bdb39" 2024-04-02 13:17:29,319 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - The request contains following session messages 2024-04-02 13:17:29,319 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - The request contains following persistent config items 2024-04-02 13:17:29,319 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - User-Password = 2024-04-02 13:17:29,319 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Persisted-User-Name = "MEDOA-WH-20" 2024-04-02 13:17:29,319 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Authentication-Source = "Local:localhost" 2024-04-02 13:17:29,319 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Authentication-Source-Name = "Endpoints Repository]" 2024-04-02 13:17:29,319 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Authentication-Source-Id = 4 2024-04-02 13:17:29,319 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - EAP-TLS-Version = "1.2" 2024-04-02 13:17:29,319 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Policy Evaluation Status: 0, Request Status: 0, Error Code: 0 2024-04-02 13:17:29,319 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - reqst_node_alloc: pkt info ptr - 0xb0047210, pkt info size 16 2024-04-02 13:17:29,319 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - reqst_node_alloc: updated pkt info - pkt # 1 2024-04-02 13:17:29,319 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Sending Access-Challenge of id 39 to 10.2.200.12 port 63420 2024-04-02 13:17:29,319 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - EAP-Message = 0x0104040a0dc000001146160303002a020000260303134c9dcda73f5aa9c0cc6f7ae655eeeb32a7ec2c071e47472beaf2fbcef196f300003d0016030303e10b0003dd0003da0003d7308203d3308202bba003020102021413166d3d1ee49e71287c71481935987990b45c08300d06092a864886f70d01010c05003072311d301b06035504030c1463796e61632e6d65646f6368656d69652e636f6d310b3009060355040b0c02495431173015060355040a0c0e4d45444f4348454d4945204c5444310b300906035504080c024359310b30090603550406130243593111300f06035504070c084c696d6173736f6c301e170d3234303430313036333531 2024-04-02 13:17:29,319 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - EAP-Message = 0x355a170d3236303430313036333531355a3072311d301b06035504030c1463796e61632e6d65646f6368656d69652e636f6d310b3009060355040b0c02495431173015060355040a0c0e4d45444f4348454d4945204c5444310b300906035504080c024359310b30090603550406130243593111300f06035504070c084c696d6173736f6c30820122300d06092a864886f70d01010105000382010f003082010a0282010100e4a548ad827feda46f706cf9703072dae3b4396554a8e5c1ddf6a6c3886ec8abc0094b18222cfa704fd55fda20b4603582ad5757e6eb6d0c6a63aae8ee5f9c4cc5025cd44ff314b64a27ab5b96ebad321271e2f01c122c 2024-04-02 13:17:29,319 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - EAP-Message = 0x08883a1fbed954ef6a9371c83589bb54800273ed2215dca9e9a01f352ddadf9eca4ed18d26acf2e4fb1f6d8ce9f0e3c5a33e532db6034a704ff79d0e0aac1ad383c3998e9799b22b4c5107dd192ed4df373d2a8a8e5ff1175955a066f19195f589d7737e1c7aa9357f82238b51cdeaa4ce78010df87114b157dd1ee01d3daa3a9776817461e75eaab64a6acaa7a0fa383ae0668c5b705b513d02a20e7af98f15a5969872a75727fc7f0203010001a361305f30150603551d11040e300c87040a02003c87040a02003d30270603551d250420301e06082b0601050507030106082b0601050507030306082b0601050507030e301d0603551d0e04160414 2024-04-02 13:17:29,319 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - EAP-Message = 0xc4ebb195f828be1f2db86fd2d32b9f03ab2a6bdd300d06092a864886f70d01010c05000382010100d18d677141456bc936d5fdb63356de172eac3159d86a1afb477ed2a3f4b3d05955942f55a846fd6519d18efc68b5019d2f5bae7dbd3d8b10fdf484859c3e0d4ed039b638ab40e8a74ccef376f0123247aa38d66bbb7f4d1557cb13b8cfa09af6fb4e405208a244dd0e50481a65a134cf79a2b6464d0aa3bb425aee02d8318cb18670390fd8ff4eb1f4a831e3e953cf32d17777d3a2d81d2001bf2e9cdb777ce2400634bd63e0abf81e6f08a16ae07f36776c1c0730613f7bede3af32ea72ba4f71a6faa552cee251e1b766fd64a690800da9d37bbc 2024-04-02 13:17:29,319 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - EAP-Message = 0x02b0990530d5eac4bc1dc75bd7e956c7ecf2da4aece6 2024-04-02 13:17:29,319 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Message-Authenticator = 0x00000000000000000000000000000000 2024-04-02 13:17:29,320 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - State = 0x414963416c77435a414d35315641674146682f477058356261546558335233675a66387a51413d3d 2024-04-02 13:17:29,320 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - reqst_update_state node pkt info ptr 0xb0047210, req cur pkt # 1, node cur pkt # 1 2024-04-02 13:17:29,320 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] INFO RadiusServer.Radius - reqst_update_state: Access-Challenge 39:1124:34-8A-12-C7-A1-34:AIcAlwCZAM51VAgAFh/GpX5baTeX3R3gZf8zQA== 2024-04-02 13:17:29,320 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Finished request 545909 2024-04-02 13:17:29,320 [Th 313 Req 545909 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Going to the next request 2024-04-02 13:17:29,330 [Th 311 Req 545910] DEBUG RadiusServer.Radius - Session-Id = "R00001e9f-01-660bdb39" 2024-04-02 13:17:29,330 [Th 311 Req 545910 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Processing the authorize section of radiusd.conf 2024-04-02 13:17:29,330 [Th 311 Req 545910 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcall: entering group authorize for request 545910 2024-04-02 13:17:29,330 [Th 311 Req 545910 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcallauthorize]: module "dacl" returns noop for request 545910 2024-04-02 13:17:29,330 [Th 311 Req 545910 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_service: The request has Service-State attribute 2024-04-02 13:17:29,331 [Th 311 Req 545910 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_service: svcreq_list_find Service-State = 0x00d9002a00b800d275540800619bf19f31a558be985c7d8711a38ce2, Session-Id = "R00001e9f-01-660bdb39" 2024-04-02 13:17:29,331 [Th 311 Req 545910 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_service: Request found, released from the list 2024-04-02 13:17:29,331 [Th 311 Req 545910 SessId R00001e9f-01-660bdb39] INFO RadiusServer.Radius - rlm_service: The request was categorized into service "MEDO-AP Wired Aruba Access Point DYN VLAN 802.1X" - 47:335:34-8A-12-C7-A1-34 2024-04-02 13:17:29,331 [Th 311 Req 545910 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_service: svcreq_list_add Service-State = 0x005f006300760094765408001d62e0666c0f3586095b7c14f1cc1a6d, Session-Id = "R00001e9f-01-660bdb39" 2024-04-02 13:17:29,331 [Th 311 Req 545910 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcallauthorize]: module "service" returns ok for request 545910 2024-04-02 13:17:29,331 [Th 311 Req 545910 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcall: leaving group authorize (returns ok) for request 545910 2024-04-02 13:17:29,331 [Th 311 Req 545910 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Found Autz-Type svc_MEDO-AP Wired Aruba Access Point DYN VLAN 802.1X_3099 2024-04-02 13:17:29,331 [Th 311 Req 545910 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Processing the authorize section of radiusd.conf 2024-04-02 13:17:29,331 [Th 311 Req 545910 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcall: entering group svc_MEDO-AP Wired Aruba Access Point DYN VLAN 802.1X_3099 for request 545910 2024-04-02 13:17:29,331 [Th 311 Req 545910 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcall: entering group for request 545910 2024-04-02 13:17:29,331 [Th 311 Req 545910 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_sql (authsrc_4): Request contains authsrc items, returning 2024-04-02 13:17:29,331 [Th 311 Req 545910 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcallauthorize]: module "authsrc_4" returns ok for request 545910 2024-04-02 13:17:29,331 [Th 311 Req 545910 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcall: leaving group (returns ok) for request 545910 2024-04-02 13:17:29,331 [Th 311 Req 545910 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap: Deleting Proxy-To-Realm and Post-Proxy-Type attributes 2024-04-02 13:17:29,331 [Th 311 Req 545910 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap: EAP packet type response id 4 length 6 2024-04-02 13:17:29,331 [Th 311 Req 545910 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap: No EAP Start, assuming it's an on-going EAP conversation 2024-04-02 13:17:29,331 [Th 311 Req 545910 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcallauthorize]: module "svc_3099_eap" returns updated for request 545910 2024-04-02 13:17:29,331 [Th 311 Req 545910 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_auth_check: Allowed authentication methods: svc_3099_eap 2024-04-02 13:17:29,331 [Th 311 Req 545910 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - radius: No MS Identity VP 2024-04-02 13:17:29,331 [Th 311 Req 545910 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_auth_check: allowed Authentication method svc_3099_eap set. 2024-04-02 13:17:29,331 [Th 311 Req 545910 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcallauthorize]: module "svc_3099_auth_check" returns ok for request 545910 2024-04-02 13:17:29,331 [Th 311 Req 545910 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcall: leaving group svc_MEDO-AP Wired Aruba Access Point DYN VLAN 802.1X_3099 (returns updated) for request 545910 2024-04-02 13:17:29,331 [Th 311 Req 545910 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rad_check_password: Found Auth-Type svc_3099_eap 2024-04-02 13:17:29,331 [Th 311 Req 545910 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - auth: type "svc_3099_eap" 2024-04-02 13:17:29,331 [Th 311 Req 545910 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Processing the authenticate section of radiusd.conf 2024-04-02 13:17:29,331 [Th 311 Req 545910 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcall: entering group svc_3099_eap for request 545910 2024-04-02 13:17:29,331 [Th 311 Req 545910 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap: eaplist_find EAP-State = 0x0023006d00d600d075540800b5c21c6681164fd3 2024-04-02 13:17:29,331 [Th 311 Req 545910 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap: Request found, released from the list 2024-04-02 13:17:29,331 [Th 311 Req 545910 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap: EAP/tls 2024-04-02 13:17:29,331 [Th 311 Req 545910 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap: processing type tls instance Medo EAP TLS without Authorization 2024-04-02 13:17:29,331 [Th 311 Req 545910 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap_tls: Authenticate 2024-04-02 13:17:29,331 [Th 311 Req 545910 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap_tls: Authorization is not mandatory 2024-04-02 13:17:29,331 [Th 311 Req 545910 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap_tls: processing TLS 2024-04-02 13:17:29,331 [Th 311 Req 545910 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap_tls: Received EAP-TLS ACK message 2024-04-02 13:17:29,332 [Th 311 Req 545910 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap_tls: ack handshake fragment handler 2024-04-02 13:17:29,332 [Th 311 Req 545910 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - eaptls_verify returned 1 2024-04-02 13:17:29,332 [Th 311 Req 545910 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - eaptls_process returned 13 2024-04-02 13:17:29,332 [Th 311 Req 545910 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap: eap_compose returned 3 2024-04-02 13:17:29,332 [Th 311 Req 545910 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap: eap_list_add EAP-State = 0x004a00b100f5008b765408005a6a1a40b8f72b94 2024-04-02 13:17:29,332 [Th 311 Req 545910 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcallauthenticate]: module "svc_3099_eap" returns handled for request 545910 2024-04-02 13:17:29,332 [Th 311 Req 545910 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcall: leaving group svc_3099_eap (returns handled) for request 545910 2024-04-02 13:17:29,332 [Th 311 Req 545910 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - The request contains following state_items 2024-04-02 13:17:29,332 [Th 311 Req 545910 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Service-State = 0x005f006300760094765408001d62e0666c0f3586095b7c14f1cc1a6d 2024-04-02 13:17:29,332 [Th 311 Req 545910 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - EAP-State = 0x004a00b100f5008b765408005a6a1a40b8f72b94 2024-04-02 13:17:29,332 [Th 311 Req 545910 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - The request contains following session_id 2024-04-02 13:17:29,332 [Th 311 Req 545910 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Session-Id = "R00001e9f-01-660bdb39" 2024-04-02 13:17:29,332 [Th 311 Req 545910 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - The request contains following session messages 2024-04-02 13:17:29,332 [Th 311 Req 545910 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - The request contains following persistent config items 2024-04-02 13:17:29,332 [Th 311 Req 545910 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - User-Password = 2024-04-02 13:17:29,332 [Th 311 Req 545910 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Persisted-User-Name = "MEDOA-WH-20" 2024-04-02 13:17:29,332 [Th 311 Req 545910 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Authentication-Source = "Local:localhost" 2024-04-02 13:17:29,332 [Th 311 Req 545910 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Authentication-Source-Name = "Endpoints Repository]" 2024-04-02 13:17:29,332 [Th 311 Req 545910 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Authentication-Source-Id = 4 2024-04-02 13:17:29,332 [Th 311 Req 545910 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - EAP-TLS-Version = "1.2" 2024-04-02 13:17:29,332 [Th 311 Req 545910 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Policy Evaluation Status: 0, Request Status: 0, Error Code: 0 2024-04-02 13:17:29,332 [Th 311 Req 545910 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - reqst_node_alloc: pkt info ptr - 0xb0047210, pkt info size 16 2024-04-02 13:17:29,332 [Th 311 Req 545910 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - reqst_node_alloc: updated pkt info - pkt # 2 2024-04-02 13:17:29,332 [Th 311 Req 545910 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Sending Access-Challenge of id 47 to 10.2.200.12 port 63420 2024-04-02 13:17:29,332 [Th 311 Req 545910 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - EAP-Message = 0x010504060d405e5798223fa92c354e9eb53fd470f5897a7c82af501603030d230d000d1f03010240002e0403050306030807080808090804080a0805080b08060401050106010303030104020502060203020203020102020ce9008b30818831143012060355040b130b446576696365547275737431133011060355040b130a4f7065726174696f6e7331173015060355040a130e4172756261204e6574776f726b73310b3009060355040613025553313530330603550403132c4172756261204e6574776f726b73205472757374656420436f6d707574696e6720526f6f7420434120312e3000633061310b30090603550406130255533115301306 2024-04-02 13:17:29,332 [Th 311 Req 545910 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - EAP-Message = 0x0355040a130c446967694365727420496e6331193017060355040b13107777772e64696769636572742e636f6d3120301e06035504031317446967694365727420476c6f62616c20526f6f74204732008b308188310b3009060355040613025553311330110603550408130a4e6577204a6572736579311430120603550407130b4a65727365792043697479311e301c060355040a131554686520555345525452555354204e6574776f726b312e302c06035504031325555345525472757374205253412043657274696669636174696f6e20417574686f726974790093308190310b3009060355040613025553312b3029060355040a13224865776c 2024-04-02 13:17:29,333 [Th 311 Req 545910 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - EAP-Message = 0x657474205061636b61726420456e746572707269736520436f6d70616e793120301e060355040b1317496e66726173747275637475726520536572766963657331323030060355040313294865776c657474205061636b61726420456e746572707269736520507269766174652053534c204341008b30818831133011060a0992268993f22c6401191603636f6d311d301b060a0992268993f22c640119160d61727562616e6574776f726b73311a3018060a0992268993f22c640119160a6465766963657369676e313630340603550403132d4172756261204e6574776f726b73205472757374656420436f6d707574696e672049737375696e6720 2024-04-02 13:17:29,333 [Th 311 Req 545910 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - EAP-Message = 0x43412032008d30818a310b300906035504061302555331173015060355040a130e4172756261204e6574776f726b7331143012060355040b130b446576696365547275737431133011060355040b130a4f7065726174696f6e73313730350603550403132e4172756261204e6574776f726b73205472757374656420436f6d707574696e6720506f6c69637920434120322e3000d53081d2310b30090603550406130255533113301106035504080c0a43616c69666f726e69613112301006035504070c0953756e6e7976616c6531173015060355040a0c0e4172756261204e6574776f726b733140303e06035504030c37436c65617250617373204f 2024-04-02 13:17:29,333 [Th 311 Req 545910 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - EAP-Message = 0x6e626f617264204c6f63616c204365727469 2024-04-02 13:17:29,333 [Th 311 Req 545910 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Message-Authenticator = 0x00000000000000000000000000000000 2024-04-02 13:17:29,333 [Th 311 Req 545910 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - State = 0x414b7341775142534143463256416741393377794474306b656969376e54704e674a6e5166673d3d 2024-04-02 13:17:29,333 [Th 311 Req 545910 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - reqst_update_state node pkt info ptr 0xb0047210, req cur pkt # 2, node cur pkt # 2 2024-04-02 13:17:29,333 [Th 311 Req 545910 SessId R00001e9f-01-660bdb39] INFO RadiusServer.Radius - reqst_update_state: Access-Challenge 47:1120:34-8A-12-C7-A1-34:AKsAwQBSACF2VAgA93wyDt0keii7nTpNgJnQfg== 2024-04-02 13:17:29,333 [Th 311 Req 545910 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Finished request 545910 2024-04-02 13:17:29,333 [Th 311 Req 545910 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Going to the next request 2024-04-02 13:17:29,342 [Th 320 Req 545911] DEBUG RadiusServer.Radius - Session-Id = "R00001e9f-01-660bdb39" 2024-04-02 13:17:29,342 [Th 320 Req 545911 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Processing the authorize section of radiusd.conf 2024-04-02 13:17:29,342 [Th 320 Req 545911 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcall: entering group authorize for request 545911 2024-04-02 13:17:29,342 [Th 320 Req 545911 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcallauthorize]: module "dacl" returns noop for request 545911 2024-04-02 13:17:29,342 [Th 320 Req 545911 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_service: The request has Service-State attribute 2024-04-02 13:17:29,342 [Th 320 Req 545911 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_service: svcreq_list_find Service-State = 0x005f006300760094765408001d62e0666c0f3586095b7c14f1cc1a6d, Session-Id = "R00001e9f-01-660bdb39" 2024-04-02 13:17:29,342 [Th 320 Req 545911 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_service: Request found, released from the list 2024-04-02 13:17:29,342 [Th 320 Req 545911 SessId R00001e9f-01-660bdb39] INFO RadiusServer.Radius - rlm_service: The request was categorized into service "MEDO-AP Wired Aruba Access Point DYN VLAN 802.1X" - 55:335:34-8A-12-C7-A1-34 2024-04-02 13:17:29,342 [Th 320 Req 545911 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_service: svcreq_list_add Service-State = 0x0065002900a3000977540800fa8c2aaa3d017ef429f4b443a3218e7a, Session-Id = "R00001e9f-01-660bdb39" 2024-04-02 13:17:29,342 [Th 320 Req 545911 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcallauthorize]: module "service" returns ok for request 545911 2024-04-02 13:17:29,342 [Th 320 Req 545911 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcall: leaving group authorize (returns ok) for request 545911 2024-04-02 13:17:29,342 [Th 320 Req 545911 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Found Autz-Type svc_MEDO-AP Wired Aruba Access Point DYN VLAN 802.1X_3099 2024-04-02 13:17:29,342 [Th 320 Req 545911 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Processing the authorize section of radiusd.conf 2024-04-02 13:17:29,342 [Th 320 Req 545911 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcall: entering group svc_MEDO-AP Wired Aruba Access Point DYN VLAN 802.1X_3099 for request 545911 2024-04-02 13:17:29,342 [Th 320 Req 545911 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcall: entering group for request 545911 2024-04-02 13:17:29,342 [Th 320 Req 545911 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_sql (authsrc_4): Request contains authsrc items, returning 2024-04-02 13:17:29,342 [Th 320 Req 545911 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcallauthorize]: module "authsrc_4" returns ok for request 545911 2024-04-02 13:17:29,342 [Th 320 Req 545911 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcall: leaving group (returns ok) for request 545911 2024-04-02 13:17:29,342 [Th 320 Req 545911 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap: Deleting Proxy-To-Realm and Post-Proxy-Type attributes 2024-04-02 13:17:29,342 [Th 320 Req 545911 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap: EAP packet type response id 5 length 6 2024-04-02 13:17:29,342 [Th 320 Req 545911 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap: No EAP Start, assuming it's an on-going EAP conversation 2024-04-02 13:17:29,342 [Th 320 Req 545911 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcallauthorize]: module "svc_3099_eap" returns updated for request 545911 2024-04-02 13:17:29,342 [Th 320 Req 545911 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_auth_check: Allowed authentication methods: svc_3099_eap 2024-04-02 13:17:29,342 [Th 320 Req 545911 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - radius: No MS Identity VP 2024-04-02 13:17:29,342 [Th 320 Req 545911 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_auth_check: allowed Authentication method svc_3099_eap set. 2024-04-02 13:17:29,342 [Th 320 Req 545911 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcallauthorize]: module "svc_3099_auth_check" returns ok for request 545911 2024-04-02 13:17:29,342 [Th 320 Req 545911 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcall: leaving group svc_MEDO-AP Wired Aruba Access Point DYN VLAN 802.1X_3099 (returns updated) for request 545911 2024-04-02 13:17:29,342 [Th 320 Req 545911 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rad_check_password: Found Auth-Type svc_3099_eap 2024-04-02 13:17:29,342 [Th 320 Req 545911 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - auth: type "svc_3099_eap" 2024-04-02 13:17:29,343 [Th 320 Req 545911 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Processing the authenticate section of radiusd.conf 2024-04-02 13:17:29,343 [Th 320 Req 545911 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcall: entering group svc_3099_eap for request 545911 2024-04-02 13:17:29,343 [Th 320 Req 545911 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap: eaplist_find EAP-State = 0x004a00b100f5008b765408005a6a1a40b8f72b94 2024-04-02 13:17:29,343 [Th 320 Req 545911 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap: Request found, released from the list 2024-04-02 13:17:29,343 [Th 320 Req 545911 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap: EAP/tls 2024-04-02 13:17:29,343 [Th 320 Req 545911 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap: processing type tls instance Medo EAP TLS without Authorization 2024-04-02 13:17:29,343 [Th 320 Req 545911 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap_tls: Authenticate 2024-04-02 13:17:29,343 [Th 320 Req 545911 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap_tls: Authorization is not mandatory 2024-04-02 13:17:29,343 [Th 320 Req 545911 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap_tls: processing TLS 2024-04-02 13:17:29,343 [Th 320 Req 545911 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap_tls: Received EAP-TLS ACK message 2024-04-02 13:17:29,343 [Th 320 Req 545911 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap_tls: ack handshake fragment handler 2024-04-02 13:17:29,343 [Th 320 Req 545911 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - eaptls_verify returned 1 2024-04-02 13:17:29,343 [Th 320 Req 545911 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - eaptls_process returned 13 2024-04-02 13:17:29,343 [Th 320 Req 545911 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap: eap_compose returned 3 2024-04-02 13:17:29,343 [Th 320 Req 545911 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap: eap_list_add EAP-State = 0x00f2002c003d004c77540800420391b683880251 2024-04-02 13:17:29,343 [Th 320 Req 545911 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcallauthenticate]: module "svc_3099_eap" returns handled for request 545911 2024-04-02 13:17:29,343 [Th 320 Req 545911 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcall: leaving group svc_3099_eap (returns handled) for request 545911 2024-04-02 13:17:29,343 [Th 320 Req 545911 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - The request contains following state_items 2024-04-02 13:17:29,343 [Th 320 Req 545911 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Service-State = 0x0065002900a3000977540800fa8c2aaa3d017ef429f4b443a3218e7a 2024-04-02 13:17:29,343 [Th 320 Req 545911 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - EAP-State = 0x00f2002c003d004c77540800420391b683880251 2024-04-02 13:17:29,343 [Th 320 Req 545911 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - The request contains following session_id 2024-04-02 13:17:29,343 [Th 320 Req 545911 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Session-Id = "R00001e9f-01-660bdb39" 2024-04-02 13:17:29,343 [Th 320 Req 545911 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - The request contains following session messages 2024-04-02 13:17:29,343 [Th 320 Req 545911 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - The request contains following persistent config items 2024-04-02 13:17:29,343 [Th 320 Req 545911 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - User-Password = 2024-04-02 13:17:29,343 [Th 320 Req 545911 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Persisted-User-Name = "MEDOA-WH-20" 2024-04-02 13:17:29,343 [Th 320 Req 545911 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Authentication-Source = "Local:localhost" 2024-04-02 13:17:29,343 [Th 320 Req 545911 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Authentication-Source-Name = "Endpoints Repository]" 2024-04-02 13:17:29,343 [Th 320 Req 545911 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Authentication-Source-Id = 4 2024-04-02 13:17:29,343 [Th 320 Req 545911 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - EAP-TLS-Version = "1.2" 2024-04-02 13:17:29,343 [Th 320 Req 545911 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Policy Evaluation Status: 0, Request Status: 0, Error Code: 0 2024-04-02 13:17:29,343 [Th 320 Req 545911 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - reqst_node_alloc: pkt info ptr - 0xb0047210, pkt info size 16 2024-04-02 13:17:29,343 [Th 320 Req 545911 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - reqst_node_alloc: updated pkt info - pkt # 3 2024-04-02 13:17:29,343 [Th 320 Req 545911 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Sending Access-Challenge of id 55 to 10.2.200.12 port 63420 2024-04-02 13:17:29,343 [Th 320 Req 545911 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - EAP-Message = 0x010604060d4066696361746520417574686f7269747920285369676e696e6729313f303d06092a864886f70d010901163038643661336164372d333334362d343162642d396165622d356161323666376163633263406578616d706c652e636f6d00cb3081c8310b30090603550406130255533113301106035504080c0a43616c69666f726e69613112301006035504070c0953756e6e7976616c6531173015060355040a0c0e4172756261204e6574776f726b733136303406035504030c2d436c65617250617373204f6e626f617264204c6f63616c20436572746966696361746520417574686f72697479313f303d06092a864886f70d01090116 2024-04-02 13:17:29,344 [Th 320 Req 545911 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - EAP-Message = 0x3038643661336164372d333334362d343162642d396165622d356161323666376163633263406578616d706c652e636f6d001f301d311b3019060355040313124d65646f6368656d696520526f6f742043410057305531153013060a0992268993f22c64011916056c6f63616c311a3018060a0992268993f22c640119160a4d45444f4348454d49453120301e060355040313174d65646f6368656d69652049737375696e67204341203100ca3081c7310b3009060355040613024359310b300906035504080c0243593111300f06035504070c084c696d6173736f6c31173015060355040a0c0e4d65646f6368656d6965204c5444310b3009060355 2024-04-02 13:17:29,344 [Th 320 Req 545911 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - EAP-Message = 0x040b0c0249543145304306035504030c3c4d65646f20436c65617250617373204f6e626f617264204c6f63616c20436572746966696361746520417574686f7269747920285369676e696e6729312b302906092a864886f70d010901161c63796265727365637572697479406d65646f6368656d69652e636f6d00c03081bd310b3009060355040613024359310b300906035504080c0243593111300f06035504070c084c696d6173736f6c31173015060355040a0c0e4d65646f6368656d6965204c5444310b3009060355040b0c024954313b303906035504030c324d65646f20436c65617250617373204f6e626f617264204c6f63616c20436572 2024-04-02 13:17:29,344 [Th 320 Req 545911 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - EAP-Message = 0x746966696361746520417574686f72697479312b302906092a864886f70d010901161c63796265727365637572697479406d65646f6368656d69652e636f6d00ab3081a8310b3009060355040613024359310b300906035504080c0243593110300e06035504070c074c656d65736f7331173015060355040a0c0e4d65646f6368656d6965204c5444310b3009060355040b0c024954312c302a06035504030c234d65646f20436c65617250617373204f6e626f61726420434120285369676e696e67293126302406092a864886f70d01090116176e657461646d696e406d65646f6368656d69652e636f6d00a130819e310b30090603550406130243 2024-04-02 13:17:29,344 [Th 320 Req 545911 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - EAP-Message = 0x59310b300906035504080c0243593110300e 2024-04-02 13:17:29,344 [Th 320 Req 545911 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Message-Authenticator = 0x00000000000000000000000000000000 2024-04-02 13:17:29,344 [Th 320 Req 545911 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - State = 0x414938414951434541505a335641674176366f57716c435479667a5270546275374b63764a513d3d 2024-04-02 13:17:29,344 [Th 320 Req 545911 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - reqst_update_state node pkt info ptr 0xb0047210, req cur pkt # 3, node cur pkt # 3 2024-04-02 13:17:29,344 [Th 320 Req 545911 SessId R00001e9f-01-660bdb39] INFO RadiusServer.Radius - reqst_update_state: Access-Challenge 55:1120:34-8A-12-C7-A1-34:AI8AIQCEAPZ3VAgAv6oWqlCTyfzRpTbu7KcvJQ== 2024-04-02 13:17:29,344 [Th 320 Req 545911 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Finished request 545911 2024-04-02 13:17:29,344 [Th 320 Req 545911 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Going to the next request 2024-04-02 13:17:29,353 [Th 312 Req 545912] DEBUG RadiusServer.Radius - Session-Id = "R00001e9f-01-660bdb39" 2024-04-02 13:17:29,353 [Th 312 Req 545912 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Processing the authorize section of radiusd.conf 2024-04-02 13:17:29,353 [Th 312 Req 545912 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcall: entering group authorize for request 545912 2024-04-02 13:17:29,353 [Th 312 Req 545912 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcallauthorize]: module "dacl" returns noop for request 545912 2024-04-02 13:17:29,353 [Th 312 Req 545912 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_service: The request has Service-State attribute 2024-04-02 13:17:29,353 [Th 312 Req 545912 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_service: svcreq_list_find Service-State = 0x0065002900a3000977540800fa8c2aaa3d017ef429f4b443a3218e7a, Session-Id = "R00001e9f-01-660bdb39" 2024-04-02 13:17:29,353 [Th 312 Req 545912 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_service: Request found, released from the list 2024-04-02 13:17:29,353 [Th 312 Req 545912 SessId R00001e9f-01-660bdb39] INFO RadiusServer.Radius - rlm_service: The request was categorized into service "MEDO-AP Wired Aruba Access Point DYN VLAN 802.1X" - 63:335:34-8A-12-C7-A1-34 2024-04-02 13:17:29,353 [Th 312 Req 545912 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_service: svcreq_list_add Service-State = 0x007b005100b900e978540800369427228903fd4c7b08b1e9218de756, Session-Id = "R00001e9f-01-660bdb39" 2024-04-02 13:17:29,353 [Th 312 Req 545912 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcallauthorize]: module "service" returns ok for request 545912 2024-04-02 13:17:29,353 [Th 312 Req 545912 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcall: leaving group authorize (returns ok) for request 545912 2024-04-02 13:17:29,354 [Th 312 Req 545912 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Found Autz-Type svc_MEDO-AP Wired Aruba Access Point DYN VLAN 802.1X_3099 2024-04-02 13:17:29,354 [Th 312 Req 545912 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Processing the authorize section of radiusd.conf 2024-04-02 13:17:29,354 [Th 312 Req 545912 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcall: entering group svc_MEDO-AP Wired Aruba Access Point DYN VLAN 802.1X_3099 for request 545912 2024-04-02 13:17:29,354 [Th 312 Req 545912 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcall: entering group for request 545912 2024-04-02 13:17:29,354 [Th 312 Req 545912 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_sql (authsrc_4): Request contains authsrc items, returning 2024-04-02 13:17:29,354 [Th 312 Req 545912 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcallauthorize]: module "authsrc_4" returns ok for request 545912 2024-04-02 13:17:29,354 [Th 312 Req 545912 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcall: leaving group (returns ok) for request 545912 2024-04-02 13:17:29,354 [Th 312 Req 545912 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap: Deleting Proxy-To-Realm and Post-Proxy-Type attributes 2024-04-02 13:17:29,354 [Th 312 Req 545912 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap: EAP packet type response id 6 length 6 2024-04-02 13:17:29,354 [Th 312 Req 545912 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap: No EAP Start, assuming it's an on-going EAP conversation 2024-04-02 13:17:29,354 [Th 312 Req 545912 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcallauthorize]: module "svc_3099_eap" returns updated for request 545912 2024-04-02 13:17:29,354 [Th 312 Req 545912 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_auth_check: Allowed authentication methods: svc_3099_eap 2024-04-02 13:17:29,354 [Th 312 Req 545912 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - radius: No MS Identity VP 2024-04-02 13:17:29,354 [Th 312 Req 545912 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_auth_check: allowed Authentication method svc_3099_eap set. 2024-04-02 13:17:29,354 [Th 312 Req 545912 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcallauthorize]: module "svc_3099_auth_check" returns ok for request 545912 2024-04-02 13:17:29,354 [Th 312 Req 545912 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcall: leaving group svc_MEDO-AP Wired Aruba Access Point DYN VLAN 802.1X_3099 (returns updated) for request 545912 2024-04-02 13:17:29,354 [Th 312 Req 545912 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rad_check_password: Found Auth-Type svc_3099_eap 2024-04-02 13:17:29,354 [Th 312 Req 545912 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - auth: type "svc_3099_eap" 2024-04-02 13:17:29,354 [Th 312 Req 545912 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Processing the authenticate section of radiusd.conf 2024-04-02 13:17:29,354 [Th 312 Req 545912 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcall: entering group svc_3099_eap for request 545912 2024-04-02 13:17:29,354 [Th 312 Req 545912 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap: eaplist_find EAP-State = 0x00f2002c003d004c77540800420391b683880251 2024-04-02 13:17:29,354 [Th 312 Req 545912 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap: Request found, released from the list 2024-04-02 13:17:29,354 [Th 312 Req 545912 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap: EAP/tls 2024-04-02 13:17:29,354 [Th 312 Req 545912 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap: processing type tls instance Medo EAP TLS without Authorization 2024-04-02 13:17:29,354 [Th 312 Req 545912 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap_tls: Authenticate 2024-04-02 13:17:29,354 [Th 312 Req 545912 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap_tls: Authorization is not mandatory 2024-04-02 13:17:29,354 [Th 312 Req 545912 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap_tls: processing TLS 2024-04-02 13:17:29,354 [Th 312 Req 545912 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap_tls: Received EAP-TLS ACK message 2024-04-02 13:17:29,354 [Th 312 Req 545912 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap_tls: ack handshake fragment handler 2024-04-02 13:17:29,354 [Th 312 Req 545912 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - eaptls_verify returned 1 2024-04-02 13:17:29,354 [Th 312 Req 545912 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - eaptls_process returned 13 2024-04-02 13:17:29,354 [Th 312 Req 545912 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap: eap_compose returned 3 2024-04-02 13:17:29,354 [Th 312 Req 545912 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap: eap_list_add EAP-State = 0x00440085009700ce78540800b7081ed5712302a2 2024-04-02 13:17:29,354 [Th 312 Req 545912 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcallauthenticate]: module "svc_3099_eap" returns handled for request 545912 2024-04-02 13:17:29,354 [Th 312 Req 545912 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcall: leaving group svc_3099_eap (returns handled) for request 545912 2024-04-02 13:17:29,354 [Th 312 Req 545912 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - The request contains following state_items 2024-04-02 13:17:29,354 [Th 312 Req 545912 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Service-State = 0x007b005100b900e978540800369427228903fd4c7b08b1e9218de756 2024-04-02 13:17:29,354 [Th 312 Req 545912 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - EAP-State = 0x00440085009700ce78540800b7081ed5712302a2 2024-04-02 13:17:29,354 [Th 312 Req 545912 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - The request contains following session_id 2024-04-02 13:17:29,354 [Th 312 Req 545912 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Session-Id = "R00001e9f-01-660bdb39" 2024-04-02 13:17:29,354 [Th 312 Req 545912 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - The request contains following session messages 2024-04-02 13:17:29,354 [Th 312 Req 545912 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - The request contains following persistent config items 2024-04-02 13:17:29,355 [Th 312 Req 545912 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - User-Password = 2024-04-02 13:17:29,355 [Th 312 Req 545912 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Persisted-User-Name = "MEDOA-WH-20" 2024-04-02 13:17:29,355 [Th 312 Req 545912 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Authentication-Source = "Local:localhost" 2024-04-02 13:17:29,355 [Th 312 Req 545912 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Authentication-Source-Name = "Endpoints Repository]" 2024-04-02 13:17:29,355 [Th 312 Req 545912 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Authentication-Source-Id = 4 2024-04-02 13:17:29,355 [Th 312 Req 545912 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - EAP-TLS-Version = "1.2" 2024-04-02 13:17:29,355 [Th 312 Req 545912 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Policy Evaluation Status: 0, Request Status: 0, Error Code: 0 2024-04-02 13:17:29,355 [Th 312 Req 545912 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - reqst_node_alloc: pkt info ptr - 0xb0047210, pkt info size 16 2024-04-02 13:17:29,355 [Th 312 Req 545912 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - reqst_node_alloc: updated pkt info - pkt # 4 2024-04-02 13:17:29,355 [Th 312 Req 545912 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Sending Access-Challenge of id 63 to 10.2.200.12 port 63420 2024-04-02 13:17:29,355 [Th 312 Req 545912 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - EAP-Message = 0x010704060d4006035504070c074c656d65736f7331173015060355040a0c0e4d65646f6368656d6965204c5444310b3009060355040b0c0249543122302006035504030c194d65646f20436c65617250617373204f6e626f6172642043413126302406092a864886f70d01090116176e657461646d696e406d65646f6368656d69652e636f6d008b308188310b3009060355040613025553311330110603550408130a4e6577204a6572736579311430120603550407130b4a65727365792043697479311e301c060355040a131554686520555345525452555354204e6574776f726b312e302c06035504031325555345525472757374204543432043 2024-04-02 13:17:29,355 [Th 312 Req 545912 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - EAP-Message = 0x657274696669636174696f6e20417574686f72697479009230818f310b3009060355040613024742311b30190603550408131247726561746572204d616e636865737465723110300e0603550407130753616c666f726431183016060355040a130f5365637469676f204c696d69746564313730350603550403132e5365637469676f2045434320446f6d61696e2056616c69646174696f6e205365637572652053657276657220434100233021311f301d0603550403131663796463312e4d45444f4348454d49452e6c6f63616c00763074310b3009060355040613024359310b30090603550408130243593111300f060355040713084c696d6173 2024-04-02 13:17:29,355 [Th 312 Req 545912 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - EAP-Message = 0x736f6c31173015060355040a130e4d65646f6368656d6965204c5444310b3009060355040b13024954311f301d0603550403131663796463322e6d65646f6368656d69652e6c6f63616c00c13081be310b300906035504061302555331163014060355040a130d456e74727573742c20496e632e31283026060355040b131f536565207777772e656e74727573742e6e65742f6c6567616c2d7465726d7331393037060355040b1330286329203230303920456e74727573742c20496e632e202d20666f7220617574686f72697a656420757365206f6e6c793132303006035504031329456e747275737420526f6f742043657274696669636174696f 2024-04-02 13:17:29,355 [Th 312 Req 545912 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - EAP-Message = 0x6e20417574686f72697479202d20473200bd3081ba310b300906035504061302555331163014060355040a130d456e74727573742c20496e632e31283026060355040b131f536565207777772e656e74727573742e6e65742f6c6567616c2d7465726d7331393037060355040b1330286329203230313220456e74727573742c20496e632e202d20666f7220617574686f72697a656420757365206f6e6c79312e302c06035504031325456e74727573742043657274696669636174696f6e20417574686f72697479202d204c314b00be3081bb310b3009060355040613024359310b300906035504080c0243593111300f06035504070c084c696d61 2024-04-02 13:17:29,355 [Th 312 Req 545912 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - EAP-Message = 0x73736f6c31133011060355040a0c0a4d6564 2024-04-02 13:17:29,355 [Th 312 Req 545912 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Message-Authenticator = 0x00000000000000000000000000000000 2024-04-02 13:17:29,355 [Th 312 Req 545912 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - State = 0x414b55414667444b414864345641674158325062386e324538786b38706378383658466970413d3d 2024-04-02 13:17:29,356 [Th 312 Req 545912 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - reqst_update_state node pkt info ptr 0xb0047210, req cur pkt # 4, node cur pkt # 4 2024-04-02 13:17:29,356 [Th 312 Req 545912 SessId R00001e9f-01-660bdb39] INFO RadiusServer.Radius - reqst_update_state: Access-Challenge 63:1120:34-8A-12-C7-A1-34:AKUAFgDKAHd4VAgAX2Pb8n2E8xk8pcx86XFipA== 2024-04-02 13:17:29,356 [Th 312 Req 545912 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Finished request 545912 2024-04-02 13:17:29,356 [Th 312 Req 545912 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Going to the next request 2024-04-02 13:17:29,364 [Th 317 Req 545913] DEBUG RadiusServer.Radius - Session-Id = "R00001e9f-01-660bdb39" 2024-04-02 13:17:29,364 [Th 317 Req 545913 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Processing the authorize section of radiusd.conf 2024-04-02 13:17:29,364 [Th 317 Req 545913 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcall: entering group authorize for request 545913 2024-04-02 13:17:29,364 [Th 317 Req 545913 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcallauthorize]: module "dacl" returns noop for request 545913 2024-04-02 13:17:29,364 [Th 317 Req 545913 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_service: The request has Service-State attribute 2024-04-02 13:17:29,364 [Th 317 Req 545913 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_service: svcreq_list_find Service-State = 0x007b005100b900e978540800369427228903fd4c7b08b1e9218de756, Session-Id = "R00001e9f-01-660bdb39" 2024-04-02 13:17:29,364 [Th 317 Req 545913 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_service: Request found, released from the list 2024-04-02 13:17:29,365 [Th 317 Req 545913 SessId R00001e9f-01-660bdb39] INFO RadiusServer.Radius - rlm_service: The request was categorized into service "MEDO-AP Wired Aruba Access Point DYN VLAN 802.1X" - 71:335:34-8A-12-C7-A1-34 2024-04-02 13:17:29,365 [Th 317 Req 545913 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_service: svcreq_list_add Service-State = 0x00fe005a006800ae79540800e9b6c67043bb0a52d9d6020c92ad106a, Session-Id = "R00001e9f-01-660bdb39" 2024-04-02 13:17:29,365 [Th 317 Req 545913 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcallauthorize]: module "service" returns ok for request 545913 2024-04-02 13:17:29,365 [Th 317 Req 545913 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcall: leaving group authorize (returns ok) for request 545913 2024-04-02 13:17:29,365 [Th 317 Req 545913 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Found Autz-Type svc_MEDO-AP Wired Aruba Access Point DYN VLAN 802.1X_3099 2024-04-02 13:17:29,365 [Th 317 Req 545913 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Processing the authorize section of radiusd.conf 2024-04-02 13:17:29,365 [Th 317 Req 545913 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcall: entering group svc_MEDO-AP Wired Aruba Access Point DYN VLAN 802.1X_3099 for request 545913 2024-04-02 13:17:29,365 [Th 317 Req 545913 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcall: entering group for request 545913 2024-04-02 13:17:29,365 [Th 317 Req 545913 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_sql (authsrc_4): Request contains authsrc items, returning 2024-04-02 13:17:29,365 [Th 317 Req 545913 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcallauthorize]: module "authsrc_4" returns ok for request 545913 2024-04-02 13:17:29,365 [Th 317 Req 545913 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcall: leaving group (returns ok) for request 545913 2024-04-02 13:17:29,365 [Th 317 Req 545913 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap: Deleting Proxy-To-Realm and Post-Proxy-Type attributes 2024-04-02 13:17:29,365 [Th 317 Req 545913 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap: EAP packet type response id 7 length 6 2024-04-02 13:17:29,365 [Th 317 Req 545913 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap: No EAP Start, assuming it's an on-going EAP conversation 2024-04-02 13:17:29,365 [Th 317 Req 545913 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcallauthorize]: module "svc_3099_eap" returns updated for request 545913 2024-04-02 13:17:29,365 [Th 317 Req 545913 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_auth_check: Allowed authentication methods: svc_3099_eap 2024-04-02 13:17:29,365 [Th 317 Req 545913 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - radius: No MS Identity VP 2024-04-02 13:17:29,365 [Th 317 Req 545913 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_auth_check: allowed Authentication method svc_3099_eap set. 2024-04-02 13:17:29,365 [Th 317 Req 545913 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcallauthorize]: module "svc_3099_auth_check" returns ok for request 545913 2024-04-02 13:17:29,365 [Th 317 Req 545913 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcall: leaving group svc_MEDO-AP Wired Aruba Access Point DYN VLAN 802.1X_3099 (returns updated) for request 545913 2024-04-02 13:17:29,365 [Th 317 Req 545913 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rad_check_password: Found Auth-Type svc_3099_eap 2024-04-02 13:17:29,365 [Th 317 Req 545913 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - auth: type "svc_3099_eap" 2024-04-02 13:17:29,365 [Th 317 Req 545913 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Processing the authenticate section of radiusd.conf 2024-04-02 13:17:29,365 [Th 317 Req 545913 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcall: entering group svc_3099_eap for request 545913 2024-04-02 13:17:29,365 [Th 317 Req 545913 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap: eaplist_find EAP-State = 0x00440085009700ce78540800b7081ed5712302a2 2024-04-02 13:17:29,365 [Th 317 Req 545913 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap: Request found, released from the list 2024-04-02 13:17:29,365 [Th 317 Req 545913 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap: EAP/tls 2024-04-02 13:17:29,365 [Th 317 Req 545913 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap: processing type tls instance Medo EAP TLS without Authorization 2024-04-02 13:17:29,365 [Th 317 Req 545913 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap_tls: Authenticate 2024-04-02 13:17:29,365 [Th 317 Req 545913 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap_tls: Authorization is not mandatory 2024-04-02 13:17:29,365 [Th 317 Req 545913 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap_tls: processing TLS 2024-04-02 13:17:29,365 [Th 317 Req 545913 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap_tls: Received EAP-TLS ACK message 2024-04-02 13:17:29,365 [Th 317 Req 545913 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap_tls: ack handshake fragment handler 2024-04-02 13:17:29,365 [Th 317 Req 545913 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - eaptls_verify returned 1 2024-04-02 13:17:29,365 [Th 317 Req 545913 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - eaptls_process returned 13 2024-04-02 13:17:29,365 [Th 317 Req 545913 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap: eap_compose returned 3 2024-04-02 13:17:29,365 [Th 317 Req 545913 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap: eap_list_add EAP-State = 0x004800c400df005c79540800ddaefa649d03a212 2024-04-02 13:17:29,365 [Th 317 Req 545913 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcallauthenticate]: module "svc_3099_eap" returns handled for request 545913 2024-04-02 13:17:29,366 [Th 317 Req 545913 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcall: leaving group svc_3099_eap (returns handled) for request 545913 2024-04-02 13:17:29,366 [Th 317 Req 545913 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - The request contains following state_items 2024-04-02 13:17:29,366 [Th 317 Req 545913 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Service-State = 0x00fe005a006800ae79540800e9b6c67043bb0a52d9d6020c92ad106a 2024-04-02 13:17:29,366 [Th 317 Req 545913 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - EAP-State = 0x004800c400df005c79540800ddaefa649d03a212 2024-04-02 13:17:29,366 [Th 317 Req 545913 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - The request contains following session_id 2024-04-02 13:17:29,366 [Th 317 Req 545913 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Session-Id = "R00001e9f-01-660bdb39" 2024-04-02 13:17:29,366 [Th 317 Req 545913 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - The request contains following session messages 2024-04-02 13:17:29,366 [Th 317 Req 545913 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - The request contains following persistent config items 2024-04-02 13:17:29,366 [Th 317 Req 545913 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - User-Password = 2024-04-02 13:17:29,366 [Th 317 Req 545913 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Persisted-User-Name = "MEDOA-WH-20" 2024-04-02 13:17:29,366 [Th 317 Req 545913 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Authentication-Source = "Local:localhost" 2024-04-02 13:17:29,366 [Th 317 Req 545913 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Authentication-Source-Name = "Endpoints Repository]" 2024-04-02 13:17:29,366 [Th 317 Req 545913 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Authentication-Source-Id = 4 2024-04-02 13:17:29,366 [Th 317 Req 545913 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - EAP-TLS-Version = "1.2" 2024-04-02 13:17:29,366 [Th 317 Req 545913 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Policy Evaluation Status: 0, Request Status: 0, Error Code: 0 2024-04-02 13:17:29,366 [Th 317 Req 545913 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - reqst_node_alloc: pkt info ptr - 0xb0047210, pkt info size 16 2024-04-02 13:17:29,366 [Th 317 Req 545913 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - reqst_node_alloc: updated pkt info - pkt # 5 2024-04-02 13:17:29,366 [Th 317 Req 545913 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Sending Access-Challenge of id 71 to 10.2.200.12 port 63420 2024-04-02 13:17:29,366 [Th 317 Req 545913 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - EAP-Message = 0x0108014c0d006f6368656d6965310b3009060355040b0c0241503142304006035504030c394d65646f202d20417275626120426f73746f6e2053656375726520496e667261737472756374757265205369676e696e67204341e2809347313126302406092a864886f70d01090116176e657461646d696e406d65646f6368656d69652e636f6d00bb3081b8310b3009060355040613024359310b300906035504080c0243593111300f06035504070c084c696d6173736f6c31133011060355040a0c0a4d65646f6368656d6965310b3009060355040b0c024150313f303d06035504030c364d65646f202d20417275626120426f73746f6e2053656375 2024-04-02 13:17:29,366 [Th 317 Req 545913 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - EAP-Message = 0x726520496e66726173747275637475726520526f6f74204341e2809347313126302406092a864886f70d01090116176e657461646d696e406d65646f6368656d69652e636f6d16030300040e000000 2024-04-02 13:17:29,366 [Th 317 Req 545913 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Message-Authenticator = 0x00000000000000000000000000000000 2024-04-02 13:17:29,366 [Th 317 Req 545913 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - State = 0x414f6f413441446a414f4a355641674135555a716c44495a3753696d5366756f4b79693549673d3d 2024-04-02 13:17:29,366 [Th 317 Req 545913 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - reqst_update_state node pkt info ptr 0xb0047210, req cur pkt # 5, node cur pkt # 5 2024-04-02 13:17:29,366 [Th 317 Req 545913 SessId R00001e9f-01-660bdb39] INFO RadiusServer.Radius - reqst_update_state: Access-Challenge 71:416:34-8A-12-C7-A1-34:AOoA4ADjAOJ5VAgA5UZqlDIZ7SimSfuoKyi5Ig== 2024-04-02 13:17:29,366 [Th 317 Req 545913 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Finished request 545913 2024-04-02 13:17:29,366 [Th 317 Req 545913 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Going to the next request 2024-04-02 13:17:29,392 [Th 318 Req 545914] DEBUG RadiusServer.Radius - Session-Id = "R00001e9f-01-660bdb39" 2024-04-02 13:17:29,392 [Th 318 Req 545914 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Processing the authorize section of radiusd.conf 2024-04-02 13:17:29,392 [Th 318 Req 545914 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcall: entering group authorize for request 545914 2024-04-02 13:17:29,392 [Th 318 Req 545914 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcallauthorize]: module "dacl" returns noop for request 545914 2024-04-02 13:17:29,392 [Th 318 Req 545914 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_service: The request has Service-State attribute 2024-04-02 13:17:29,392 [Th 318 Req 545914 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_service: svcreq_list_find Service-State = 0x00fe005a006800ae79540800e9b6c67043bb0a52d9d6020c92ad106a, Session-Id = "R00001e9f-01-660bdb39" 2024-04-02 13:17:29,392 [Th 318 Req 545914 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_service: Request found, released from the list 2024-04-02 13:17:29,392 [Th 318 Req 545914 SessId R00001e9f-01-660bdb39] INFO RadiusServer.Radius - rlm_service: The request was categorized into service "MEDO-AP Wired Aruba Access Point DYN VLAN 802.1X" - 79:335:34-8A-12-C7-A1-34 2024-04-02 13:17:29,392 [Th 318 Req 545914 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_service: svcreq_list_add Service-State = 0x00dd001000fe00d47a54080094e5e9532eaab099ed38f0d224989718, Session-Id = "R00001e9f-01-660bdb39" 2024-04-02 13:17:29,392 [Th 318 Req 545914 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcallauthorize]: module "service" returns ok for request 545914 2024-04-02 13:17:29,392 [Th 318 Req 545914 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcall: leaving group authorize (returns ok) for request 545914 2024-04-02 13:17:29,392 [Th 318 Req 545914 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Found Autz-Type svc_MEDO-AP Wired Aruba Access Point DYN VLAN 802.1X_3099 2024-04-02 13:17:29,392 [Th 318 Req 545914 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Processing the authorize section of radiusd.conf 2024-04-02 13:17:29,392 [Th 318 Req 545914 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcall: entering group svc_MEDO-AP Wired Aruba Access Point DYN VLAN 802.1X_3099 for request 545914 2024-04-02 13:17:29,392 [Th 318 Req 545914 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcall: entering group for request 545914 2024-04-02 13:17:29,393 [Th 318 Req 545914 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_sql (authsrc_4): Request contains authsrc items, returning 2024-04-02 13:17:29,393 [Th 318 Req 545914 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcallauthorize]: module "authsrc_4" returns ok for request 545914 2024-04-02 13:17:29,393 [Th 318 Req 545914 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcall: leaving group (returns ok) for request 545914 2024-04-02 13:17:29,393 [Th 318 Req 545914 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap: Deleting Proxy-To-Realm and Post-Proxy-Type attributes 2024-04-02 13:17:29,393 [Th 318 Req 545914 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap: EAP packet type response id 8 length 6 2024-04-02 13:17:29,393 [Th 318 Req 545914 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap: No EAP Start, assuming it's an on-going EAP conversation 2024-04-02 13:17:29,393 [Th 318 Req 545914 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcallauthorize]: module "svc_3099_eap" returns updated for request 545914 2024-04-02 13:17:29,393 [Th 318 Req 545914 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_auth_check: Allowed authentication methods: svc_3099_eap 2024-04-02 13:17:29,393 [Th 318 Req 545914 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - radius: No MS Identity VP 2024-04-02 13:17:29,393 [Th 318 Req 545914 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_auth_check: allowed Authentication method svc_3099_eap set. 2024-04-02 13:17:29,393 [Th 318 Req 545914 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcallauthorize]: module "svc_3099_auth_check" returns ok for request 545914 2024-04-02 13:17:29,393 [Th 318 Req 545914 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcall: leaving group svc_MEDO-AP Wired Aruba Access Point DYN VLAN 802.1X_3099 (returns updated) for request 545914 2024-04-02 13:17:29,393 [Th 318 Req 545914 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rad_check_password: Found Auth-Type svc_3099_eap 2024-04-02 13:17:29,393 [Th 318 Req 545914 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - auth: type "svc_3099_eap" 2024-04-02 13:17:29,393 [Th 318 Req 545914 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Processing the authenticate section of radiusd.conf 2024-04-02 13:17:29,393 [Th 318 Req 545914 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcall: entering group svc_3099_eap for request 545914 2024-04-02 13:17:29,393 [Th 318 Req 545914 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap: eaplist_find EAP-State = 0x004800c400df005c79540800ddaefa649d03a212 2024-04-02 13:17:29,393 [Th 318 Req 545914 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap: Request found, released from the list 2024-04-02 13:17:29,393 [Th 318 Req 545914 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap: EAP/tls 2024-04-02 13:17:29,393 [Th 318 Req 545914 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap: processing type tls instance Medo EAP TLS without Authorization 2024-04-02 13:17:29,394 [Th 318 Req 545914 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap_tls: Authenticate 2024-04-02 13:17:29,394 [Th 318 Req 545914 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap_tls: Authorization is not mandatory 2024-04-02 13:17:29,394 [Th 318 Req 545914 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap_tls: processing TLS 2024-04-02 13:17:29,394 [Th 318 Req 545914 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap_tls: Received EAP-TLS ACK message 2024-04-02 13:17:29,394 [Th 318 Req 545914 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap_tls: ack handshake fragment handler 2024-04-02 13:17:29,394 [Th 318 Req 545914 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - eaptls_verify returned 1 2024-04-02 13:17:29,394 [Th 318 Req 545914 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - eaptls_process returned 13 2024-04-02 13:17:29,394 [Th 318 Req 545914 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap: eap_compose returned 3 2024-04-02 13:17:29,394 [Th 318 Req 545914 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap: eap_list_add EAP-State = 0x0064006a00db00817a540800c1832c90cfc49c8f 2024-04-02 13:17:29,394 [Th 318 Req 545914 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcallauthenticate]: module "svc_3099_eap" returns handled for request 545914 2024-04-02 13:17:29,394 [Th 318 Req 545914 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcall: leaving group svc_3099_eap (returns handled) for request 545914 2024-04-02 13:17:29,394 [Th 318 Req 545914 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - The request contains following state_items 2024-04-02 13:17:29,394 [Th 318 Req 545914 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Service-State = 0x00dd001000fe00d47a54080094e5e9532eaab099ed38f0d224989718 2024-04-02 13:17:29,394 [Th 318 Req 545914 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - EAP-State = 0x0064006a00db00817a540800c1832c90cfc49c8f 2024-04-02 13:17:29,394 [Th 318 Req 545914 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - The request contains following session_id 2024-04-02 13:17:29,394 [Th 318 Req 545914 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Session-Id = "R00001e9f-01-660bdb39" 2024-04-02 13:17:29,394 [Th 318 Req 545914 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - The request contains following session messages 2024-04-02 13:17:29,394 [Th 318 Req 545914 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - The request contains following persistent config items 2024-04-02 13:17:29,394 [Th 318 Req 545914 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - User-Password = 2024-04-02 13:17:29,394 [Th 318 Req 545914 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Persisted-User-Name = "MEDOA-WH-20" 2024-04-02 13:17:29,394 [Th 318 Req 545914 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Authentication-Source = "Local:localhost" 2024-04-02 13:17:29,394 [Th 318 Req 545914 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Authentication-Source-Name = "Endpoints Repository]" 2024-04-02 13:17:29,394 [Th 318 Req 545914 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Authentication-Source-Id = 4 2024-04-02 13:17:29,394 [Th 318 Req 545914 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - EAP-TLS-Version = "1.2" 2024-04-02 13:17:29,395 [Th 318 Req 545914 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Policy Evaluation Status: 0, Request Status: 0, Error Code: 0 2024-04-02 13:17:29,395 [Th 318 Req 545914 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - reqst_node_alloc: pkt info ptr - 0xb0047210, pkt info size 16 2024-04-02 13:17:29,395 [Th 318 Req 545914 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - reqst_node_alloc: updated pkt info - pkt # 6 2024-04-02 13:17:29,395 [Th 318 Req 545914 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Sending Access-Challenge of id 79 to 10.2.200.12 port 63420 2024-04-02 13:17:29,395 [Th 318 Req 545914 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - EAP-Message = 0x0109000a0d8000000000 2024-04-02 13:17:29,395 [Th 318 Req 545914 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Message-Authenticator = 0x00000000000000000000000000000000 2024-04-02 13:17:29,395 [Th 318 Req 545914 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - State = 0x414d3441647743774145313656416741472b757a306b4f787958445933552b496371772b32773d3d 2024-04-02 13:17:29,395 [Th 318 Req 545914 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - reqst_update_state node pkt info ptr 0xb0047210, req cur pkt # 6, node cur pkt # 6 2024-04-02 13:17:29,395 [Th 318 Req 545914 SessId R00001e9f-01-660bdb39] INFO RadiusServer.Radius - reqst_update_state: Access-Challenge 79:92:34-8A-12-C7-A1-34:AM4AdwCwAE16VAgAG+uz0kOxyXDY3U+Icqw+2w== 2024-04-02 13:17:29,395 [Th 318 Req 545914 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Finished request 545914 2024-04-02 13:17:29,395 [Th 318 Req 545914 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Going to the next request 2024-04-02 13:17:29,404 [Th 316 Req 545915] DEBUG RadiusServer.Radius - Session-Id = "R00001e9f-01-660bdb39" 2024-04-02 13:17:29,404 [Th 316 Req 545915 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Processing the authorize section of radiusd.conf 2024-04-02 13:17:29,404 [Th 316 Req 545915 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcall: entering group authorize for request 545915 2024-04-02 13:17:29,404 [Th 316 Req 545915 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcallauthorize]: module "dacl" returns noop for request 545915 2024-04-02 13:17:29,404 [Th 316 Req 545915 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_service: The request has Service-State attribute 2024-04-02 13:17:29,404 [Th 316 Req 545915 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_service: svcreq_list_find Service-State = 0x00dd001000fe00d47a54080094e5e9532eaab099ed38f0d224989718, Session-Id = "R00001e9f-01-660bdb39" 2024-04-02 13:17:29,404 [Th 316 Req 545915 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_service: Request found, released from the list 2024-04-02 13:17:29,404 [Th 316 Req 545915 SessId R00001e9f-01-660bdb39] INFO RadiusServer.Radius - rlm_service: The request was categorized into service "MEDO-AP Wired Aruba Access Point DYN VLAN 802.1X" - 87:335:34-8A-12-C7-A1-34 2024-04-02 13:17:29,404 [Th 316 Req 545915 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_service: svcreq_list_add Service-State = 0x006d00a9009c00527b5408000a8c02d29904494d3e9855ced44660ea, Session-Id = "R00001e9f-01-660bdb39" 2024-04-02 13:17:29,404 [Th 316 Req 545915 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcallauthorize]: module "service" returns ok for request 545915 2024-04-02 13:17:29,404 [Th 316 Req 545915 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcall: leaving group authorize (returns ok) for request 545915 2024-04-02 13:17:29,404 [Th 316 Req 545915 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Found Autz-Type svc_MEDO-AP Wired Aruba Access Point DYN VLAN 802.1X_3099 2024-04-02 13:17:29,404 [Th 316 Req 545915 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Processing the authorize section of radiusd.conf 2024-04-02 13:17:29,404 [Th 316 Req 545915 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcall: entering group svc_MEDO-AP Wired Aruba Access Point DYN VLAN 802.1X_3099 for request 545915 2024-04-02 13:17:29,404 [Th 316 Req 545915 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcall: entering group for request 545915 2024-04-02 13:17:29,404 [Th 316 Req 545915 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_sql (authsrc_4): Request contains authsrc items, returning 2024-04-02 13:17:29,404 [Th 316 Req 545915 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcallauthorize]: module "authsrc_4" returns ok for request 545915 2024-04-02 13:17:29,404 [Th 316 Req 545915 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcall: leaving group (returns ok) for request 545915 2024-04-02 13:17:29,404 [Th 316 Req 545915 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap: Deleting Proxy-To-Realm and Post-Proxy-Type attributes 2024-04-02 13:17:29,404 [Th 316 Req 545915 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap: EAP packet type response id 9 length 6 2024-04-02 13:17:29,405 [Th 316 Req 545915 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap: No EAP Start, assuming it's an on-going EAP conversation 2024-04-02 13:17:29,405 [Th 316 Req 545915 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcallauthorize]: module "svc_3099_eap" returns updated for request 545915 2024-04-02 13:17:29,405 [Th 316 Req 545915 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_auth_check: Allowed authentication methods: svc_3099_eap 2024-04-02 13:17:29,405 [Th 316 Req 545915 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - radius: No MS Identity VP 2024-04-02 13:17:29,405 [Th 316 Req 545915 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_auth_check: allowed Authentication method svc_3099_eap set. 2024-04-02 13:17:29,405 [Th 316 Req 545915 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcallauthorize]: module "svc_3099_auth_check" returns ok for request 545915 2024-04-02 13:17:29,405 [Th 316 Req 545915 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcall: leaving group svc_MEDO-AP Wired Aruba Access Point DYN VLAN 802.1X_3099 (returns updated) for request 545915 2024-04-02 13:17:29,405 [Th 316 Req 545915 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rad_check_password: Found Auth-Type svc_3099_eap 2024-04-02 13:17:29,405 [Th 316 Req 545915 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - auth: type "svc_3099_eap" 2024-04-02 13:17:29,405 [Th 316 Req 545915 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Processing the authenticate section of radiusd.conf 2024-04-02 13:17:29,405 [Th 316 Req 545915 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcall: entering group svc_3099_eap for request 545915 2024-04-02 13:17:29,405 [Th 316 Req 545915 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap: eaplist_find EAP-State = 0x0064006a00db00817a540800c1832c90cfc49c8f 2024-04-02 13:17:29,405 [Th 316 Req 545915 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap: Request found, released from the list 2024-04-02 13:17:29,405 [Th 316 Req 545915 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap: EAP/tls 2024-04-02 13:17:29,405 [Th 316 Req 545915 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap: processing type tls instance Medo EAP TLS without Authorization 2024-04-02 13:17:29,405 [Th 316 Req 545915 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap_tls: Authenticate 2024-04-02 13:17:29,405 [Th 316 Req 545915 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap_tls: Authorization is not mandatory 2024-04-02 13:17:29,405 [Th 316 Req 545915 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap_tls: processing TLS 2024-04-02 13:17:29,405 [Th 316 Req 545915 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap_tls: Received EAP-TLS ACK message 2024-04-02 13:17:29,405 [Th 316 Req 545915 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap_tls: ack handshake fragment handler 2024-04-02 13:17:29,405 [Th 316 Req 545915 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - eaptls_verify returned 1 2024-04-02 13:17:29,405 [Th 316 Req 545915 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - eaptls_process returned 13 2024-04-02 13:17:29,405 [Th 316 Req 545915 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap: eap_compose returned 3 2024-04-02 13:17:29,405 [Th 316 Req 545915 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_eap: eap_list_add EAP-State = 0x00f0000000d5006e7b54080067023412e5651bd8 2024-04-02 13:17:29,405 [Th 316 Req 545915 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcallauthenticate]: module "svc_3099_eap" returns handled for request 545915 2024-04-02 13:17:29,405 [Th 316 Req 545915 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcall: leaving group svc_3099_eap (returns handled) for request 545915 2024-04-02 13:17:29,405 [Th 316 Req 545915 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - The request contains following state_items 2024-04-02 13:17:29,405 [Th 316 Req 545915 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Service-State = 0x006d00a9009c00527b5408000a8c02d29904494d3e9855ced44660ea 2024-04-02 13:17:29,405 [Th 316 Req 545915 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - EAP-State = 0x00f0000000d5006e7b54080067023412e5651bd8 2024-04-02 13:17:29,405 [Th 316 Req 545915 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - The request contains following session_id 2024-04-02 13:17:29,405 [Th 316 Req 545915 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Session-Id = "R00001e9f-01-660bdb39" 2024-04-02 13:17:29,405 [Th 316 Req 545915 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - The request contains following session messages 2024-04-02 13:17:29,405 [Th 316 Req 545915 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - The request contains following persistent config items 2024-04-02 13:17:29,405 [Th 316 Req 545915 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - User-Password = 2024-04-02 13:17:29,405 [Th 316 Req 545915 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Persisted-User-Name = "MEDOA-WH-20" 2024-04-02 13:17:29,405 [Th 316 Req 545915 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Authentication-Source = "Local:localhost" 2024-04-02 13:17:29,405 [Th 316 Req 545915 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Authentication-Source-Name = "Endpoints Repository]" 2024-04-02 13:17:29,405 [Th 316 Req 545915 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Authentication-Source-Id = 4 2024-04-02 13:17:29,406 [Th 316 Req 545915 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - EAP-TLS-Version = "1.2" 2024-04-02 13:17:29,406 [Th 316 Req 545915 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Policy Evaluation Status: 0, Request Status: 0, Error Code: 0 2024-04-02 13:17:29,406 [Th 316 Req 545915 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - reqst_node_alloc: pkt info ptr - 0xb0047210, pkt info size 16 2024-04-02 13:17:29,406 [Th 316 Req 545915 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - reqst_node_alloc: updated pkt info - pkt # 7 2024-04-02 13:17:29,406 [Th 316 Req 545915 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Sending Access-Challenge of id 87 to 10.2.200.12 port 63420 2024-04-02 13:17:29,406 [Th 316 Req 545915 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - EAP-Message = 0x010a000a0d8000000000 2024-04-02 13:17:29,406 [Th 316 Req 545915 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Message-Authenticator = 0x00000000000000000000000000000000 2024-04-02 13:17:29,406 [Th 316 Req 545915 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - State = 0x414667414451423341424637564167416a374963414a74794c3476465677685943556f7a38513d3d 2024-04-02 13:17:29,406 [Th 316 Req 545915 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - reqst_update_state node pkt info ptr 0xb0047210, req cur pkt # 7, node cur pkt # 7 2024-04-02 13:17:29,406 [Th 316 Req 545915 SessId R00001e9f-01-660bdb39] INFO RadiusServer.Radius - reqst_update_state: Access-Challenge 87:92:34-8A-12-C7-A1-34:AFgADQB3ABF7VAgAj7IcAJtyL4vFVwhYCUoz8Q== 2024-04-02 13:17:29,406 [Th 316 Req 545915 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Finished request 545915 2024-04-02 13:17:29,406 [Th 316 Req 545915 SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Going to the next request 2024-04-02 13:18:15,291 [main SessId R00001e9f-01-660bdb39] ERROR RadiusServer.Radius - reqst_clean_list: Deleting request sessid - R00001e9f-01-660bdb39, state - AFgADQB3ABF7VAgAj7IcAJtyL4vFVwhYCUoz8Q= 2024-04-02 13:18:15,291 [main SessId R00001e9f-01-660bdb39] ERROR RadiusServer.Radius - reqst_clean_list: Packet 31:303:88:34-8A-12-C7-A1-34 recv 1712053049.297182 - resp 1712053049.307895 2024-04-02 13:18:15,291 [main SessId R00001e9f-01-660bdb39] ERROR RadiusServer.Radius - reqst_clean_list: Packet 39:419:1124:34-8A-12-C7-A1-34 recv 1712053049.317522 - resp 1712053049.320027 2024-04-02 13:18:15,291 [main SessId R00001e9f-01-660bdb39] ERROR RadiusServer.Radius - reqst_clean_list: Packet 47:335:1120:34-8A-12-C7-A1-34 recv 1712053049.329577 - resp 1712053049.333236 2024-04-02 13:18:15,291 [main SessId R00001e9f-01-660bdb39] ERROR RadiusServer.Radius - reqst_clean_list: Packet 55:335:1120:34-8A-12-C7-A1-34 recv 1712053049.341135 - resp 1712053049.344319 2024-04-02 13:18:15,291 [main SessId R00001e9f-01-660bdb39] ERROR RadiusServer.Radius - reqst_clean_list: Packet 63:335:1120:34-8A-12-C7-A1-34 recv 1712053049.352280 - resp 1712053049.355937 2024-04-02 13:18:15,291 [main SessId R00001e9f-01-660bdb39] ERROR RadiusServer.Radius - reqst_clean_list: Packet 71:335:416:34-8A-12-C7-A1-34 recv 1712053049.363476 - resp 1712053049.366711 2024-04-02 13:18:15,291 [main SessId R00001e9f-01-660bdb39] ERROR RadiusServer.Radius - reqst_clean_list: Packet 79:335:92:34-8A-12-C7-A1-34 recv 1712053049.390464 - resp 1712053049.395333 2024-04-02 13:18:15,291 [main SessId R00001e9f-01-660bdb39] ERROR RadiusServer.Radius - reqst_clean_list: Packet 87:335:92:34-8A-12-C7-A1-34 recv 1712053049.402827 - resp 1712053049.406210 2024-04-02 13:18:15,291 [main SessId R00001e9f-01-660bdb39] INFO RadiusServer.Radius - Last EAP Packet Processing Time = 3 ms 2024-04-02 13:18:15,291 [main SessId R00001e9f-01-660bdb39] DEBUG StatsDClient.StatsClient - Formatted StatsD data=default.cynac1.radius.timedoutpkt.count:1|c 2024-04-02 13:18:15,292 [main SessId R00001e9f-01-660bdb39] DEBUG StatsDClient.StatsClient - Sending StatsD request=default.cynac1.radius.timedoutpkt.count:1|c 2024-04-02 13:18:15,292 [main SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - adding alert message Last EAP Packet Processing Time = 3 ms 2024-04-02 13:18:15,292 [main SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Found Post-Auth-Type 2024-04-02 13:18:15,292 [main SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Processing the post-auth section of radiusd.conf 2024-04-02 13:18:15,292 [main SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcall: entering group REJECT for request 0 2024-04-02 13:18:15,292 [main SessId R00001e9f-01-660bdb39] INFO RadiusServer.Radius - rlm_policy: Starting Policy Evaluation. 2024-04-02 13:18:15,292 [main SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_policy: policy_get_polsvr_conn: Checking Id: 0 2024-04-02 13:18:15,292 [main SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_policy: policy_get_polsvr_conn: Got Id: 0, handle: 0x162e4e0 2024-04-02 13:18:15,292 [main SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_policy: policy_add_request_vps 2024-04-02 13:18:15,292 [main SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - User-Name = "MEDOA-WH-20" 2024-04-02 13:18:15,292 [main SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Service-Type = Framed-User 2024-04-02 13:18:15,292 [main SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Cisco-AVPair = "service-type=Framed" 2024-04-02 13:18:15,292 [main SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Framed-MTU = 1468 2024-04-02 13:18:15,292 [main SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_policy: skipping attribute EAP-Message in policy_add_request_vps 2024-04-02 13:18:15,292 [main SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_policy: skipping attribute Message-Authenticator in policy_add_request_vps 2024-04-02 13:18:15,292 [main SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Cisco-AVPair = "audit-session-id=0CC8020A000080F09E3B65BA" 2024-04-02 13:18:15,292 [main SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Cisco-AVPair = "method=dot1x" 2024-04-02 13:18:15,292 [main SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Cisco-AVPair = "client-iif-id=338979414" 2024-04-02 13:18:15,292 [main SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - NAS-IP-Address = 10.2.200.12 2024-04-02 13:18:15,292 [main SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - NAS-Port-Id = "GigabitEthernet4/0/26" 2024-04-02 13:18:15,293 [main SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - NAS-Port-Type = Ethernet 2024-04-02 13:18:15,293 [main SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - NAS-Port = 50426 2024-04-02 13:18:15,293 [main SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Calling-Station-Id = "34-8A-12-C7-A1-34" 2024-04-02 13:18:15,293 [main SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - NAS-Identifier = "Pegasus_FL01" 2024-04-02 13:18:15,293 [main SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Called-Station-Id = "74-88-BB-F4-1D-9A" 2024-04-02 13:18:15,293 [main SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_policy: policy_add_config_vps - Request has the following config items 2024-04-02 13:18:15,293 [main SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Session-Id = "R00001e9f-01-660bdb39" 2024-04-02 13:18:15,293 [main SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - User-Password = 2024-04-02 13:18:15,293 [main SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Persisted-User-Name = "MEDOA-WH-20" 2024-04-02 13:18:15,293 [main SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Authentication-Source = "Local:localhost" 2024-04-02 13:18:15,293 [main SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Authentication-Source-Name = "Endpoints Repository]" 2024-04-02 13:18:15,293 [main SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Authentication-Source-Id = 4 2024-04-02 13:18:15,293 [main SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - EAP-TLS-Version = "1.2" 2024-04-02 13:18:15,293 [main SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Service-Name = "MEDO-AP Wired Aruba Access Point DYN VLAN 802.1X" 2024-04-02 13:18:15,293 [main SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Service-Id = 3099 2024-04-02 13:18:15,293 [main SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Autz-Type = svc_MEDO-AP Wired Aruba Access Point DYN VLAN 802.1X_3099 2024-04-02 13:18:15,293 [main SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Auth-Type = svc_3099_eap 2024-04-02 13:18:15,293 [main SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Authentication-EAP-Method = "tls" 2024-04-02 13:18:15,293 [main SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Authentication-Method = "EAP" 2024-04-02 13:18:15,293 [main SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Post-Auth-Type = REJECT 2024-04-02 13:18:15,293 [main SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Service-Name = "MEDO-AP Wired Aruba Access Point DYN VLAN 802.1X" 2024-04-02 13:18:15,293 [main SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Session-Id = "R00001e9f-01-660bdb39" 2024-04-02 13:18:15,293 [main SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Authentication-Source-Id = 4 2024-04-02 13:18:15,293 [main SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_policy: policy_add_reply_vps 2024-04-02 13:18:15,293 [main SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_policy: policy_add_conn_info 2024-04-02 13:18:15,293 [main SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_policy: Adding Connection:Src-IP-Address=10.2.200.12 2024-04-02 13:18:15,293 [main SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_policy: Adding Connection:NAD-IP-Address=10.2.200.12 2024-04-02 13:18:15,293 [main SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_policy: Adding Connection:Dest-IP-Address=10.2.0.60 2024-04-02 13:18:15,293 [main SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_policy: policy_add_authentication_attributes 2024-04-02 13:18:15,293 [main SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_policy: not computed Authentication:TLS-Version 2024-04-02 13:18:15,294 [main SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_policy: policy_add_authorization_attributes 2024-04-02 13:18:15,294 [main SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_policy: policy_add_certificate_attributes 2024-04-02 13:18:15,294 [main SessId R00001e9f-01-660bdb39] DEBUG StatsDClient.StatsClient - Formatted StatsD data=default.cynac1.radius.auth._Endpoints_Repository_.failure:1|c 2024-04-02 13:18:15,294 [main SessId R00001e9f-01-660bdb39] DEBUG StatsDClient.StatsClient - Sending StatsD request=default.cynac1.radius.auth._Endpoints_Repository_.failure:1|c 2024-04-02 13:18:15,294 [main SessId R00001e9f-01-660bdb39] DEBUG StatsDClient.StatsClient - Formatted StatsD data=default.cynac1.radius.auth.failure:1|c 2024-04-02 13:18:15,294 [main SessId R00001e9f-01-660bdb39] DEBUG StatsDClient.StatsClient - Sending StatsD request=default.cynac1.radius.auth.failure:1|c 2024-04-02 13:18:15,294 [main SessId R00001e9f-01-660bdb39] DEBUG StatsDClient.StatsClient - Formatted StatsD data=default.cynac1.radius.auth._Endpoints_Repository_.count:1|c 2024-04-02 13:18:15,294 [main SessId R00001e9f-01-660bdb39] DEBUG StatsDClient.StatsClient - Sending StatsD request=default.cynac1.radius.auth._Endpoints_Repository_.count:1|c 2024-04-02 13:18:15,294 [main SessId R00001e9f-01-660bdb39] DEBUG StatsDClient.StatsClient - Formatted StatsD data=default.cynac1.radius.auth.count:1|c 2024-04-02 13:18:15,294 [main SessId R00001e9f-01-660bdb39] DEBUG StatsDClient.StatsClient - Sending StatsD request=default.cynac1.radius.auth.count:1|c 2024-04-02 13:18:15,299 [RequestHandler-1-0x7f2883fff700 r=psauto-1711690116-87644 h=239 r=R00001e9f-01-660bdb39] INFO Common.EndpointTable - Returning EndpointSPtr for macAddr 348a12c7a134 2024-04-02 13:18:15,299 [RequestHandler-1-0x7f2883fff700 r=psauto-1711690116-87644 h=239 r=R00001e9f-01-660bdb39] INFO Common.TagDefinitionCacheTable - No InstanceTagDefCacheMap found for instance id = 3031 entity id = 29 2024-04-02 13:18:15,299 [RequestHandler-1-0x7f2883fff700 r=psauto-1711690116-87644 h=239 r=R00001e9f-01-660bdb39] INFO Common.TagDefinitionCacheTable - Building the TagDefMapTable for NAD instance=3031 2024-04-02 13:18:15,299 [RequestHandler-1-0x7f2883fff700 r=psauto-1711690116-87644 h=239 r=R00001e9f-01-660bdb39] INFO Common.TagDefinitionCacheTable - Built 0 tag(s) for NAD instanceId=3031|entityId=29 2024-04-02 13:18:15,299 [RequestHandler-1-0x7f2883fff700 r=psauto-1711690116-87644 h=239 r=R00001e9f-01-660bdb39] INFO TAT.TagAttrHolderBuilder - No tags built for instanceId=3031|entity=Device 2024-04-02 13:18:15,299 [RequestHandler-1-0x7f2883fff700 r=psauto-1711690116-87644 h=239 r=R00001e9f-01-660bdb39] INFO TAT.AluTagAttrHolderBuilder - buildAttrHolder: Tags cannot be built for instanceId=0 (NULL AuthLocalUser) 2024-04-02 13:18:15,299 [RequestHandler-1-0x7f2883fff700 r=psauto-1711690116-87644 h=239 r=R00001e9f-01-660bdb39] INFO TAT.GuTagAttrHolderBuilder - buildAttrHolder: Tags cannot be built for instanceId=0 (NULL GuestUser) 2024-04-02 13:18:15,299 [RequestHandler-1-0x7f2883fff700 r=psauto-1711690116-87644 h=239 r=R00001e9f-01-660bdb39] INFO Common.TagDefinitionCacheTable - No TagDefCacheMap could be found for instance id = 9190 entity id = 72 2024-04-02 13:18:15,299 [RequestHandler-1-0x7f2883fff700 r=psauto-1711690116-87644 h=239 r=R00001e9f-01-660bdb39] INFO Common.TagDefinitionCacheTable - Building the TagDefMapTable for Endpoint instance=9190 2024-04-02 13:18:15,299 [RequestHandler-1-0x7f2883fff700 r=psauto-1711690116-87644 h=239 r=R00001e9f-01-660bdb39] INFO Common.TagDefinitionCacheTable - Built 0 tag(s) for instanceId=9190|entityId=72|entityName=Endpoint 2024-04-02 13:18:15,299 [RequestHandler-1-0x7f2883fff700 r=psauto-1711690116-87644 h=239 r=R00001e9f-01-660bdb39] INFO TAT.TagAttrHolderBuilder - No tags built for instanceId=9190|entity=Endpoint 2024-04-02 13:18:15,299 [RequestHandler-1-0x7f2883fff700 r=psauto-1711690116-87644 h=239 r=R00001e9f-01-660bdb39] INFO TAT.OnboardTagAttrHolderBuilder - buildAttrHolder: Tags cannot be built for instanceId=0 (NULL Onboard Device User) 2024-04-02 13:18:15,300 [RequestHandler-1-0x7f2883fff700 h=733703 c=R00001e9f-01-660bdb39] INFO Core.PETaskScheduler - *** PE_TASK_SCHEDULE_RADIUS Started *** 2024-04-02 13:18:15,300 [RequestHandler-1-0x7f2883fff700 h=733703 c=R00001e9f-01-660bdb39] INFO Core.PETaskScheduler - ** Starting PETaskAuthSourceRestriction ** 2024-04-02 13:18:15,300 [RequestHandler-1-0x7f2883fff700 h=733703 c=R00001e9f-01-660bdb39] INFO Core.PETaskScheduler - ** Starting PETaskRoleMapping ** 2024-04-02 13:18:15,301 [RequestHandler-1-0x7f2883fff700 r=R00001e9f-01-660bdb39 h=733703 c=R00001e9f-01-660bdb39] INFO Core.PETaskScheduler - ** Completed PETaskAuthSourceRestriction ** 2024-04-02 13:18:15,305 [RequestHandler-1-0x7f2883fff700 h=733705 c=R00001e9f-01-660bdb39] INFO Core.PETaskRoleMapping - Roles: Medo - Aruba Access Point 2024-04-02 13:18:15,305 [RequestHandler-1-0x7f2883fff700 r=R00001e9f-01-660bdb39 h=733703 c=R00001e9f-01-660bdb39] INFO Core.PETaskScheduler - ** Completed PETaskRoleMapping ** 2024-04-02 13:18:15,305 [RequestHandler-1-0x7f2883fff700 r=R00001e9f-01-660bdb39 h=733703 c=R00001e9f-01-660bdb39] INFO Core.PETaskScheduler - ** Starting PETaskPolicyResult ** 2024-04-02 13:18:15,305 [RequestHandler-1-0x7f2883fff700 r=R00001e9f-01-660bdb39 h=733703 c=R00001e9f-01-660bdb39] INFO Core.PETaskScheduler - ** Completed PETaskPolicyResult ** 2024-04-02 13:18:15,306 [RequestHandler-1-0x7f2883fff700 r=R00001e9f-01-660bdb39 h=733703 c=R00001e9f-01-660bdb39] INFO Core.PETaskScheduler - ** Starting PETaskEnforcement ** 2024-04-02 13:18:15,306 [RequestHandler-1-0x7f2883fff700 h=733708 c=R00001e9f-01-660bdb39] INFO Core.PETaskEnforcement - EnfProfiles: Update Endpoint Known], Medo VL-100] 802.1X Wired AAA Aruba AP], Medo Wired Filter-ID - ALLOWALL 2024-04-02 13:18:15,307 [RequestHandler-1-0x7f2883fff700 r=R00001e9f-01-660bdb39 h=733703 c=R00001e9f-01-660bdb39] INFO Core.PETaskScheduler - ** Completed PETaskEnforcement ** 2024-04-02 13:18:15,307 [RequestHandler-1-0x7f2883fff700 r=R00001e9f-01-660bdb39 h=733703 c=R00001e9f-01-660bdb39] INFO Core.PETaskScheduler - ** Starting PETaskRadiusEnfProfileBuilder ** 2024-04-02 13:18:15,307 [RequestHandler-1-0x7f2883fff700 r=R00001e9f-01-660bdb39 h=733703 c=R00001e9f-01-660bdb39] INFO Core.PETaskScheduler - ** Starting PETaskRadiusCoAEnfProfileBuilder ** 2024-04-02 13:18:15,307 [RequestHandler-1-0x7f2883fff700 r=R00001e9f-01-660bdb39 h=733703 c=R00001e9f-01-660bdb39] INFO Core.PETaskScheduler - ** Starting PETaskAppEnfProfileBuilder ** 2024-04-02 13:18:15,307 [RequestHandler-1-0x7f2883fff700 r=R00001e9f-01-660bdb39 h=733703 c=R00001e9f-01-660bdb39] INFO Core.PETaskScheduler - ** Starting PETaskAgentEnfProfileBuilder ** 2024-04-02 13:18:15,307 [RequestHandler-1-0x7f2883fff700 r=R00001e9f-01-660bdb39 h=733703 c=R00001e9f-01-660bdb39] INFO Core.PETaskScheduler - ** Starting PETaskPostAuthEnfProfileBuilder ** 2024-04-02 13:18:15,307 [RequestHandler-1-0x7f2883fff700 r=R00001e9f-01-660bdb39 h=733703 c=R00001e9f-01-660bdb39] INFO Core.PETaskScheduler - ** Starting PETaskGenericEnfProfileBuilder ** 2024-04-02 13:18:15,307 [RequestHandler-1-0x7f2883fff700 h=733714 c=R00001e9f-01-660bdb39] INFO Core.PETaskGenericEnfProfileBuilder - getApplicableProfiles: No App enforcement (Generic) profiles applicable for this device 2024-04-02 13:18:15,307 [RequestHandler-1-0x7f2883fff700 h=733711 c=R00001e9f-01-660bdb39] WARN Common.AppEnfProfileTable - getAppType: Failed for id=51 2024-04-02 13:18:15,308 [RequestHandler-1-0x7f2883fff700 h=733709 c=R00001e9f-01-660bdb39] INFO Core.PETaskRadiusEnfProfileBuilder - EnfProfileAction=ACCEPT 2024-04-02 13:18:15,308 [RequestHandler-1-0x7f2883fff700 h=733709 c=R00001e9f-01-660bdb39] INFO Core.PETaskRadiusEnfProfileBuilder - Radius enfProfiles used: Medo VL-100] 802.1X Wired AAA Aruba AP], Medo Wired Filter-ID - ALLOWALL 2024-04-02 13:18:15,308 [RequestHandler-1-0x7f2883fff700 h=733709 c=R00001e9f-01-660bdb39] INFO Core.EnfProfileComputer - getFinalSessionTimeout: sessionTimeout = 86400 2024-04-02 13:18:15,308 [RequestHandler-1-0x7f2883fff700 r=R00001e9f-01-660bdb39 h=733703 c=R00001e9f-01-660bdb39] INFO Core.PETaskScheduler - ** Completed PETaskGenericEnfProfileBuilder ** 2024-04-02 13:18:15,308 [RequestHandler-1-0x7f2883fff700 r=R00001e9f-01-660bdb39 h=733703 c=R00001e9f-01-660bdb39] INFO Core.PETaskScheduler - ** Completed PETaskAgentEnfProfileBuilder ** 2024-04-02 13:18:15,308 [RequestHandler-1-0x7f2883fff700 r=R00001e9f-01-660bdb39 h=733703 c=R00001e9f-01-660bdb39] INFO Core.PETaskScheduler - ** Completed PETaskAppEnfProfileBuilder ** 2024-04-02 13:18:15,309 [RequestHandler-1-0x7f2883fff700 r=R00001e9f-01-660bdb39 h=733703 c=R00001e9f-01-660bdb39] INFO Core.PETaskScheduler - ** Starting PETaskCliEnforcement ** 2024-04-02 13:18:15,309 [RequestHandler-1-0x7f2883fff700 h=733715 c=R00001e9f-01-660bdb39] INFO Core.PETaskCliEnforcement - startHandler: No commands for CLI enforcement 2024-04-02 13:18:15,309 [RequestHandler-1-0x7f2883fff700 r=R00001e9f-01-660bdb39 h=733703 c=R00001e9f-01-660bdb39] INFO Core.PETaskScheduler - ** Completed PETaskRadiusEnfProfileBuilder ** 2024-04-02 13:18:15,309 [RequestHandler-1-0x7f2883fff700 r=R00001e9f-01-660bdb39 h=733713 c=R00001e9f-01-660bdb39] INFO Core.PETaskPostAuthEnfProfileBuilder - Post auth enforcement profiles used: Update Endpoint Known] 2024-04-02 13:18:15,309 [RequestHandler-1-0x7f2883fff700 r=R00001e9f-01-660bdb39 h=733713 c=R00001e9f-01-660bdb39] INFO Core.PETaskPostAuthEnfProfileBuilder - UnknownAutzParams to fetch for PostAuthEnfProfiles: : 2024-04-02 13:18:15,309 [RequestHandler-1-0x7f2883fff700 r=R00001e9f-01-660bdb39 h=733713 c=R00001e9f-01-660bdb39] INFO Core.PETaskPostAuthEnfProfileBuilder - UnknownNAutzParams to fetch for PostAuthEnfProfiles: : 2024-04-02 13:18:15,309 [RequestHandler-1-0x7f2883fff700 r=R00001e9f-01-660bdb39 h=733713 c=R00001e9f-01-660bdb39] INFO Common.EndpointTable - Returning EndpointSPtr for macAddr 348a12c7a134 2024-04-02 13:18:15,309 [RequestHandler-1-0x7f2883fff700 r=R00001e9f-01-660bdb39 h=733713 c=R00001e9f-01-660bdb39] INFO Core.PETaskPostAuthEnfProfileBuilder - Discarding attr name=Status-Update:Endpoint|attr value=Known as the entity = 348a12c7a134 already possesses this value 2024-04-02 13:18:15,309 [RequestHandler-1-0x7f2883fff700 r=R00001e9f-01-660bdb39 h=733713 c=R00001e9f-01-660bdb39] INFO Core.PETaskPostAuthEnfProfileBuilder - sendPostAuthHTTPRequest: Sending PostAuthEnfRequest {"content":{"auth_source_id":0,"mac_address":"348a12c7a134","nas_ip":"10.2.200.12","post_auth_actions":{"enf_profile_name":"Update Endpoint Known]","enf_profile_type":"EntityUpdate","params":null}],"user_id":"MEDOA-WH-20"},"id":"R00004758-01-66092efe","name":"pactrl_enf_request"} 2024-04-02 13:18:15,310 [RequestHandler-1-0x7f2883fff700 r=R00001e9f-01-660bdb39 h=733713 c=R00001e9f-01-660bdb39] INFO Core.PETaskPostAuthEnfProfileBuilder - sendPostAuthResponse: Done sending the PostAuthEnfRequest 2024-04-02 13:18:15,310 [RequestHandler-1-0x7f2883fff700 r=R00001e9f-01-660bdb39 h=733710 c=R00001e9f-01-660bdb39] INFO Core.PETaskRadiusCoAEnfProfileBuilder - getApplicableProfiles: No radius_coa enforcement profiles applicable for this device 2024-04-02 13:18:15,310 [RequestHandler-1-0x7f2883fff700 r=R00001e9f-01-660bdb39 h=733703 c=R00001e9f-01-660bdb39] INFO Core.PETaskScheduler - ** Completed PETaskCliEnforcement ** 2024-04-02 13:18:15,310 [RequestHandler-1-0x7f2883fff700 r=R00001e9f-01-660bdb39 h=733703 c=R00001e9f-01-660bdb39] INFO Core.PETaskScheduler - ** Completed PETaskPostAuthEnfProfileBuilder ** 2024-04-02 13:18:15,310 [RequestHandler-1-0x7f2883fff700 r=R00001e9f-01-660bdb39 h=733703 c=R00001e9f-01-660bdb39] INFO Core.PETaskScheduler - ** Completed PETaskRadiusCoAEnfProfileBuilder ** 2024-04-02 13:18:15,310 [RequestHandler-1-0x7f2883fff700 r=R00001e9f-01-660bdb39 h=733703 c=R00001e9f-01-660bdb39] INFO Core.PETaskScheduler - ** Starting PETaskAuthStatusInfo ** 2024-04-02 13:18:15,310 [RequestHandler-1-0x7f2883fff700 r=R00001e9f-01-660bdb39 h=733703 c=R00001e9f-01-660bdb39] INFO Core.PETaskScheduler - ** Starting PETaskOutputPolicyRes ** 2024-04-02 13:18:15,310 [RequestHandler-1-0x7f2883fff700 r=R00001e9f-01-660bdb39 h=733703 c=R00001e9f-01-660bdb39] INFO Core.PETaskScheduler - ** Starting PETaskSessionLog ** 2024-04-02 13:18:15,314 [RequestHandler-1-0x7f2883fff700 h=733717 c=R00001e9f-01-660bdb39] INFO Core.XpipPolicyResHandler - populateResponseTlv: PETaskPostureOutput does not exist. Skip sending posture VAFs 2024-04-02 13:18:15,314 [RequestHandler-1-0x7f2883fff700 h=733717 c=R00001e9f-01-660bdb39] INFO Core.PolicyResCollector - getSohr: Failed to generate Sohr 2024-04-02 13:18:15,315 [main SessId R00001e9f-01-660bdb39] DEBUG StatsDClient.StatsClient - Formatted StatsD data=default.cynac1.radius.policyeval.time:20|ms 2024-04-02 13:18:15,315 [main SessId R00001e9f-01-660bdb39] DEBUG StatsDClient.StatsClient - Sending StatsD request=default.cynac1.radius.policyeval.time:20|ms 2024-04-02 13:18:15,315 [main SessId R00001e9f-01-660bdb39] INFO RadiusServer.Radius - Policy Evaluation time = 20 ms 2024-04-02 13:18:15,315 [main SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_policy: policy_add_resp_attrs 2024-04-02 13:18:15,315 [main SessId R00001e9f-01-660bdb39] INFO RadiusServer.Radius - rlm_policy: Received Accept Enforcement Profile 2024-04-02 13:18:15,315 [main SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_policy: Request rejected. Not adding Class attribute. 2024-04-02 13:18:15,315 [main SessId R00001e9f-01-660bdb39] INFO RadiusServer.Radius - rlm_policy: Policy Server reply does not contain Posture-Validation-Response 2024-04-02 13:18:15,315 [main SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - Request Policy Evaluation Status: 1, Request Status: 3 2024-04-02 13:18:15,315 [RequestHandler-1-0x7f2883fff700 h=733716 c=R00001e9f-01-660bdb39] INFO Core.PolicyResCollector - getSohr: Failed to generate Sohr 2024-04-02 13:18:15,315 [RequestHandler-1-0x7f2883fff700 r=R00001e9f-01-660bdb39 h=733703 c=R00001e9f-01-660bdb39] INFO Core.PETaskScheduler - ** Completed PETaskSessionLog ** 2024-04-02 13:18:15,315 [RequestHandler-1-0x7f2883fff700 r=R00001e9f-01-660bdb39 h=733703 c=R00001e9f-01-660bdb39] INFO Core.PETaskScheduler - ** Completed PETaskOutputPolicyRes ** 2024-04-02 13:18:15,315 [RequestHandler-1-0x7f2883fff700 r=R00001e9f-01-660bdb39 h=733703 c=R00001e9f-01-660bdb39] INFO Core.PETaskScheduler - ** Completed PETaskAuthStatusInfo ** 2024-04-02 13:18:15,315 [RequestHandler-1-0x7f2883fff700 r=R00001e9f-01-660bdb39 h=733703 c=R00001e9f-01-660bdb39] INFO Core.PETaskScheduler - *** PE_TASK_SCHEDULE_RADIUS Completed *** 2024-04-02 13:18:15,316 [main SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - adding alert message Client did not complete EAP transaction 2024-04-02 13:18:15,316 [main SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - rlm_policy: policy_release_polsvr_conn: Release Id: 0, handle: 0x162e4e0 2024-04-02 13:18:15,316 [main SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcallpost-auth]: module "policy" returns reject for request 0 2024-04-02 13:18:15,316 [main SessId R00001e9f-01-660bdb39] DEBUG RadiusServer.Radius - modcall: leaving group REJECT (returns reject) for request 0