Request log details for session: R0000003b-01-660ad310 Time Message 2024-04-01 18:30:24,595 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Processing the authorize section of radiusd.conf 2024-04-01 18:30:24,595 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: entering group authorize for request 4770 2024-04-01 18:30:24,595 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallauthorize]: module "dacl" returns noop for request 4770 2024-04-01 18:30:24,595 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_service: The request does not have Service-State attribute 2024-04-01 18:30:24,595 [Th 37 Req 4770 SessId R0000003b-01-660ad310] INFO RadiusServer.Radius - rlm_service: Starting Service Categorization - 138:409:48-4a-e9-c8-59-c4 2024-04-01 18:30:24,595 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_service: service_get_polsvr_conn: Checking Id: 0 2024-04-01 18:30:24,595 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_service: service_get_polsvr_conn: Got Id: 0, handle: 0xf89190 2024-04-01 18:30:24,595 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_service: add req-packet attributes 2024-04-01 18:30:24,595 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Framed-MTU = 3038 2024-04-01 18:30:24,595 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - NAS-IP-Address = 10.2.200.32 2024-04-01 18:30:24,595 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - NAS-Identifier = "MedoB-Entrance" 2024-04-01 18:30:24,595 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - User-Name = "MedoB_Training" 2024-04-01 18:30:24,595 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Service-Type = Framed-User 2024-04-01 18:30:24,595 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Framed-Protocol = PPP 2024-04-01 18:30:24,595 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - NAS-Port = 29 2024-04-01 18:30:24,595 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - NAS-Port-Type = Ethernet 2024-04-01 18:30:24,595 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - NAS-Port-Id = "1/29" 2024-04-01 18:30:24,595 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Called-Station-Id = "38-10-f0-54-37-ca" 2024-04-01 18:30:24,595 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Calling-Station-Id = "48-4a-e9-c8-59-c4" 2024-04-01 18:30:24,595 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Connect-Info = "CONNECT Ethernet 1000Mbps Full duplex" 2024-04-01 18:30:24,595 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Tunnel-Type:0 = VLAN 2024-04-01 18:30:24,595 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Tunnel-Medium-Type:0 = IEEE-802 2024-04-01 18:30:24,595 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Tunnel-Private-Group-Id:0 = "100" 2024-04-01 18:30:24,595 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - EAP-Message = 0x02010013014d65646f425f547261696e696e67 2024-04-01 18:30:24,595 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Message-Authenticator = 0x75a2b01c51367551b42047d142743dec 2024-04-01 18:30:24,595 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - MS-RAS-Vendor = 11 2024-04-01 18:30:24,595 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - HPE-Capability-Advertisement = "??" 2024-04-01 18:30:24,595 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - HPE-Capability-Advertisement = "??" 2024-04-01 18:30:24,595 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - HPE-Capability-Advertisement = "??" 2024-04-01 18:30:24,595 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - HPE-Capability-Advertisement = "??" 2024-04-01 18:30:24,595 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - HPE-Capability-Advertisement = "??" 2024-04-01 18:30:24,595 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - HPE-Capability-Advertisement = "??" 2024-04-01 18:30:24,595 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - HPE-Capability-Advertisement = "??" 2024-04-01 18:30:24,595 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - HPE-Capability-Advertisement = "??" 2024-04-01 18:30:24,596 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - HPE-Capability-Advertisement = "?8" 2024-04-01 18:30:24,596 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - HPE-Capability-Advertisement = "?:" 2024-04-01 18:30:24,596 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - HPE-Capability-Advertisement = "?@" 2024-04-01 18:30:24,596 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - HPE-Capability-Advertisement = "?A" 2024-04-01 18:30:24,596 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - HPE-Capability-Advertisement = "?Q" 2024-04-01 18:30:24,596 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_service: add config attributes 2024-04-01 18:30:24,596 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Session-Id = "R0000003b-01-660ad310" 2024-04-01 18:30:24,596 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_service: add connection attributes 2024-04-01 18:30:24,596 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_service: Adding Connection:Src-IP-Address=10.2.200.32 2024-04-01 18:30:24,596 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_service: Adding Connection:NAD-IP-Address=10.2.200.32 2024-04-01 18:30:24,596 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_service: Adding Connection:Dest-IP-Address=10.2.0.60 2024-04-01 18:30:24,607 [RequestHandler-1-0x7f2883fff700 r=psauto-1711690116-69417 h=223 r=R0000003b-01-660ad310] INFO Core.ServiceReqHandler - Service classification result = {ArubaOS SW} Wired Desktop DYN VLAN 802.1X 2024-04-01 18:30:24,608 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG StatsDClient.StatsClient - Formatted StatsD data=default.cynac1.radius.serviceeval.time:12|ms 2024-04-01 18:30:24,608 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG StatsDClient.StatsClient - Sending StatsD request=default.cynac1.radius.serviceeval.time:12|ms 2024-04-01 18:30:24,608 [Th 37 Req 4770 SessId R0000003b-01-660ad310] INFO RadiusServer.Radius - Service Categorization time = 12 ms 2024-04-01 18:30:24,608 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_service: Policy Server reply does not contain Requested-Posture-Credentials 2024-04-01 18:30:24,608 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_service: service_release_polsvr_conn: Release Id: 0, handle: 0xf89190 2024-04-01 18:30:24,608 [Th 37 Req 4770 SessId R0000003b-01-660ad310] INFO RadiusServer.Radius - rlm_service: The request has been categorized into service "{ArubaOS SW} Wired Desktop DYN VLAN 802.1X" 2024-04-01 18:30:24,608 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_service: Checking for username before "@" 2024-04-01 18:30:24,608 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_service: No delimiter. 2024-04-01 18:30:24,608 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_service: svcreq_list_add Service-State = 0x00c9009f000000caa2120000c775082503a8a93b107bd4491ce8363b, Session-Id = "R0000003b-01-660ad310" 2024-04-01 18:30:24,608 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallauthorize]: module "service" returns ok for request 4770 2024-04-01 18:30:24,608 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: leaving group authorize (returns ok) for request 4770 2024-04-01 18:30:24,608 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Found Autz-Type svc_{ArubaOS SW} Wired Desktop DYN VLAN 802.1X_3056 2024-04-01 18:30:24,608 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Processing the authorize section of radiusd.conf 2024-04-01 18:30:24,608 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: entering group svc_{ArubaOS SW} Wired Desktop DYN VLAN 802.1X_3056 for request 4770 2024-04-01 18:30:24,608 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: entering group for request 4770 2024-04-01 18:30:24,608 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: entering redundant-sticky group for request 4770 2024-04-01 18:30:24,608 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Redundant-sticky: Module authsrc_3001 is active 2024-04-01 18:30:24,608 [Th 37 Req 4770 SessId R0000003b-01-660ad310] INFO RadiusServer.Radius - rlm_ldap: searching for user MedoB_Training in AD:cydc2.medochemie.local 2024-04-01 18:30:24,608 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - radius_xlat: Running registered xlat function of module authsrc_3001 for string 'Username' 2024-04-01 18:30:24,608 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_ldap: - ldap_xlat 2024-04-01 18:30:24,608 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - radius_xlat: '(&(sAMAccountName=MedoB_Training)(objectClass=user))' 2024-04-01 18:30:24,608 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - radius_xlat: 'dc=medochemie,dc=local' 2024-04-01 18:30:24,608 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_ldap: ldap_get_conn: Checking Id: 0 2024-04-01 18:30:24,608 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_ldap: ldap_get_conn: Got Id: 0 2024-04-01 18:30:24,608 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_ldap: Allocated referral parameters dn = cpassad@medochemie.local & password 2024-04-01 18:30:24,608 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_ldap: performing search in dc=medochemie,dc=local, with filter (&(sAMAccountName=MedoB_Training)(objectClass=user)) 2024-04-01 18:30:24,609 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_ldap: object not found or got ambiguous search result 2024-04-01 18:30:24,609 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_ldap: search failed 2024-04-01 18:30:24,609 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_ldap: ldap_release_conn: Release Id: 0 2024-04-01 18:30:24,609 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallauthorize]: module "authsrc_3001" returns notfound for request 4770 2024-04-01 18:30:24,609 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: redundant-sticky group returns notfound for request 4770 2024-04-01 18:30:24,609 [Th 37 Req 4770 SessId R0000003b-01-660ad310] INFO RadiusServer.Radius - rlm_sql: searching for user MedoB_Training in Local:localhost 2024-04-01 18:30:24,609 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - radius_xlat: Running registered xlat function of module Connection for string 'Client-Mac-Address-NoDelim' 2024-04-01 18:30:24,609 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - radius_xlat: 'SELECT mac_address AS User_Password FROM tips_endpoints WHERE mac_address = LOWER('484ae9c859c4') AND status = 'Known'' 2024-04-01 18:30:24,609 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_sql (authsrc_4): Reserving sql socket id: 31 2024-04-01 18:30:24,610 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_sql: The number of fields: 1. 2024-04-01 18:30:24,610 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_sql: Coulmn label user_password 2024-04-01 18:30:24,610 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_sql (authsrc_4): User MedoB_Training found 2024-04-01 18:30:24,610 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_sql (authsrc_4): Released sql socket id: 31 2024-04-01 18:30:24,610 [Th 37 Req 4770 SessId R0000003b-01-660ad310] INFO RadiusServer.Radius - rlm_sql: found user MedoB_Training in Local:localhost 2024-04-01 18:30:24,610 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_sql: Adding Persisted-User-Name MedoB_Training to persistent items 2024-04-01 18:30:24,610 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG StatsDClient.StatsClient - Formatted StatsD data=default.cynac1.radius.auth._Endpoints_Repository_.lookup-time:1|ms 2024-04-01 18:30:24,610 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG StatsDClient.StatsClient - Sending StatsD request=default.cynac1.radius.auth._Endpoints_Repository_.lookup-time:1|ms 2024-04-01 18:30:24,610 [Th 37 Req 4770 SessId R0000003b-01-660ad310] INFO RadiusServer.Radius - SQL User lookup time = 1 ms 2024-04-01 18:30:24,610 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG StatsDClient.StatsClient - Formatted StatsD data=default.cynac1.radius.auth.time:1|ms 2024-04-01 18:30:24,610 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG StatsDClient.StatsClient - Sending StatsD request=default.cynac1.radius.auth.time:1|ms 2024-04-01 18:30:24,610 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallauthorize]: module "authsrc_4" returns ok for request 4770 2024-04-01 18:30:24,610 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: leaving group (returns ok) for request 4770 2024-04-01 18:30:24,610 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: Deleting Proxy-To-Realm and Post-Proxy-Type attributes 2024-04-01 18:30:24,611 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: EAP packet type response id 1 length 19 2024-04-01 18:30:24,611 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: No EAP Start, assuming it's an on-going EAP conversation 2024-04-01 18:30:24,611 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallauthorize]: module "svc_3056_eap" returns updated for request 4770 2024-04-01 18:30:24,611 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_auth_check: Allowed authentication methods: svc_3056_eap 2024-04-01 18:30:24,611 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - radius: No MS Identity VP 2024-04-01 18:30:24,611 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_auth_check: allowed Authentication method svc_3056_eap set. 2024-04-01 18:30:24,611 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallauthorize]: module "svc_3056_auth_check" returns ok for request 4770 2024-04-01 18:30:24,611 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: leaving group svc_{ArubaOS SW} Wired Desktop DYN VLAN 802.1X_3056 (returns updated) for request 4770 2024-04-01 18:30:24,611 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rad_check_password: Found Auth-Type svc_3056_eap 2024-04-01 18:30:24,611 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - auth: type "svc_3056_eap" 2024-04-01 18:30:24,611 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Processing the authenticate section of radiusd.conf 2024-04-01 18:30:24,611 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: entering group svc_3056_eap for request 4770 2024-04-01 18:30:24,611 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: EAP Identity 2024-04-01 18:30:24,611 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: processing type peap instance EAP PEAP] 2024-04-01 18:30:24,611 [Th 37 Req 4770 SessId R0000003b-01-660ad310] INFO RadiusServer.Radius - rlm_eap_peap: Initiate 2024-04-01 18:30:24,611 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap_tls: Start returned 1 2024-04-01 18:30:24,611 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: eap_compose returned 3 2024-04-01 18:30:24,611 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: eap_list_add EAP-State = 0x00d8002e000f001ea2120000d6a3a4d015f01dbc 2024-04-01 18:30:24,611 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallauthenticate]: module "svc_3056_eap" returns handled for request 4770 2024-04-01 18:30:24,611 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: leaving group svc_3056_eap (returns handled) for request 4770 2024-04-01 18:30:24,611 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - The request contains following state_items 2024-04-01 18:30:24,611 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Service-State = 0x00c9009f000000caa2120000c775082503a8a93b107bd4491ce8363b 2024-04-01 18:30:24,611 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - EAP-State = 0x00d8002e000f001ea2120000d6a3a4d015f01dbc 2024-04-01 18:30:24,611 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - The request contains following session_id 2024-04-01 18:30:24,611 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Session-Id = "R0000003b-01-660ad310" 2024-04-01 18:30:24,611 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - The request contains following session messages 2024-04-01 18:30:24,611 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - The request contains following persistent config items 2024-04-01 18:30:24,611 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - User-Password = 2024-04-01 18:30:24,611 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Persisted-User-Name = "MedoB_Training" 2024-04-01 18:30:24,611 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Authentication-Source = "Local:localhost" 2024-04-01 18:30:24,611 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Authentication-Source-Name = "Endpoints Repository]" 2024-04-01 18:30:24,611 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Authentication-Source-Id = 4 2024-04-01 18:30:24,611 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Policy Evaluation Status: 0, Request Status: 0, Error Code: 201 2024-04-01 18:30:24,611 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - reqst_node_alloc: allocating pkt info - 0x5c01d750, pkt info size 16 2024-04-01 18:30:24,611 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - reqst_node_alloc: updated pkt info - pkt # 0 2024-04-01 18:30:24,611 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Sending Access-Challenge of id 138 to 10.2.200.32 port 1812 2024-04-01 18:30:24,611 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - EAP-Message = 0x010200061921 2024-04-01 18:30:24,611 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Message-Authenticator = 0x00000000000000000000000000000000 2024-04-01 18:30:24,611 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - State = 0x414d63414e5143584142656945674141437571615862686d63645538567634527346613544673d3d 2024-04-01 18:30:24,611 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - reqst_update_state node pkt info ptr 0x5c01d750, req cur pkt # 0, node cur pkt # 0 2024-04-01 18:30:24,611 [Th 37 Req 4770 SessId R0000003b-01-660ad310] INFO RadiusServer.Radius - reqst_update_state: Access-Challenge 138:88:48-4a-e9-c8-59-c4:AMcANQCXABeiEgAACuqaXbhmcdU8Vv4RsFa5Dg== 2024-04-01 18:30:24,611 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Finished request 4770 2024-04-01 18:30:24,611 [Th 37 Req 4770 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Going to the next request 2024-04-01 18:30:24,615 [Th 38 Req 4771] DEBUG RadiusServer.Radius - Session-Id = "R0000003b-01-660ad310" 2024-04-01 18:30:24,615 [Th 38 Req 4771 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Processing the authorize section of radiusd.conf 2024-04-01 18:30:24,615 [Th 38 Req 4771 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: entering group authorize for request 4771 2024-04-01 18:30:24,615 [Th 38 Req 4771 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallauthorize]: module "dacl" returns noop for request 4771 2024-04-01 18:30:24,615 [Th 38 Req 4771 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_service: The request has Service-State attribute 2024-04-01 18:30:24,615 [Th 38 Req 4771 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_service: svcreq_list_find Service-State = 0x00c9009f000000caa2120000c775082503a8a93b107bd4491ce8363b, Session-Id = "R0000003b-01-660ad310" 2024-04-01 18:30:24,615 [Th 38 Req 4771 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_service: Request found, released from the list 2024-04-01 18:30:24,615 [Th 38 Req 4771 SessId R0000003b-01-660ad310] INFO RadiusServer.Radius - rlm_service: The request was categorized into service "{ArubaOS SW} Wired Desktop DYN VLAN 802.1X" - 139:438:48-4a-e9-c8-59-c4 2024-04-01 18:30:24,615 [Th 38 Req 4771 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_service: Checking for username before "@" 2024-04-01 18:30:24,615 [Th 38 Req 4771 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_service: No delimiter. 2024-04-01 18:30:24,615 [Th 38 Req 4771 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_service: svcreq_list_add Service-State = 0x00a2004a003b0003a3120000c1f91301d61330982cca5bcbc64bc7cf, Session-Id = "R0000003b-01-660ad310" 2024-04-01 18:30:24,615 [Th 38 Req 4771 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallauthorize]: module "service" returns ok for request 4771 2024-04-01 18:30:24,615 [Th 38 Req 4771 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: leaving group authorize (returns ok) for request 4771 2024-04-01 18:30:24,615 [Th 38 Req 4771 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Found Autz-Type svc_{ArubaOS SW} Wired Desktop DYN VLAN 802.1X_3056 2024-04-01 18:30:24,615 [Th 38 Req 4771 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Processing the authorize section of radiusd.conf 2024-04-01 18:30:24,615 [Th 38 Req 4771 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: entering group svc_{ArubaOS SW} Wired Desktop DYN VLAN 802.1X_3056 for request 4771 2024-04-01 18:30:24,616 [Th 38 Req 4771 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: entering group for request 4771 2024-04-01 18:30:24,616 [Th 38 Req 4771 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: entering redundant-sticky group for request 4771 2024-04-01 18:30:24,616 [Th 38 Req 4771 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Redundant-sticky: Module authsrc_3001 is active 2024-04-01 18:30:24,616 [Th 38 Req 4771 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_ldap: Request contains authsrc items, returning 2024-04-01 18:30:24,616 [Th 38 Req 4771 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallauthorize]: module "authsrc_3001" returns notfound for request 4771 2024-04-01 18:30:24,616 [Th 38 Req 4771 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: redundant-sticky group returns notfound for request 4771 2024-04-01 18:30:24,616 [Th 38 Req 4771 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_sql (authsrc_4): Request contains authsrc items, returning 2024-04-01 18:30:24,616 [Th 38 Req 4771 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallauthorize]: module "authsrc_4" returns ok for request 4771 2024-04-01 18:30:24,616 [Th 38 Req 4771 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: leaving group (returns ok) for request 4771 2024-04-01 18:30:24,616 [Th 38 Req 4771 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: Deleting Proxy-To-Realm and Post-Proxy-Type attributes 2024-04-01 18:30:24,616 [Th 38 Req 4771 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: EAP packet type response id 2 length 6 2024-04-01 18:30:24,616 [Th 38 Req 4771 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: No EAP Start, assuming it's an on-going EAP conversation 2024-04-01 18:30:24,616 [Th 38 Req 4771 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallauthorize]: module "svc_3056_eap" returns updated for request 4771 2024-04-01 18:30:24,616 [Th 38 Req 4771 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_auth_check: Allowed authentication methods: svc_3056_eap 2024-04-01 18:30:24,616 [Th 38 Req 4771 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - radius: No MS Identity VP 2024-04-01 18:30:24,616 [Th 38 Req 4771 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_auth_check: allowed Authentication method svc_3056_eap set. 2024-04-01 18:30:24,616 [Th 38 Req 4771 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallauthorize]: module "svc_3056_auth_check" returns ok for request 4771 2024-04-01 18:30:24,616 [Th 38 Req 4771 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: leaving group svc_{ArubaOS SW} Wired Desktop DYN VLAN 802.1X_3056 (returns updated) for request 4771 2024-04-01 18:30:24,616 [Th 38 Req 4771 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rad_check_password: Found Auth-Type svc_3056_eap 2024-04-01 18:30:24,616 [Th 38 Req 4771 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - auth: type "svc_3056_eap" 2024-04-01 18:30:24,616 [Th 38 Req 4771 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Processing the authenticate section of radiusd.conf 2024-04-01 18:30:24,616 [Th 38 Req 4771 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: entering group svc_3056_eap for request 4771 2024-04-01 18:30:24,616 [Th 38 Req 4771 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: eaplist_find EAP-State = 0x00d8002e000f001ea2120000d6a3a4d015f01dbc 2024-04-01 18:30:24,616 [Th 38 Req 4771 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap_tls: SSL ex data at index 1 - (nil) 2024-04-01 18:30:24,616 [Th 38 Req 4771 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: Request found, released from the list 2024-04-01 18:30:24,616 [Th 38 Req 4771 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: EAP-NAK asked for EAP-Type/tls 2024-04-01 18:30:24,616 [Th 38 Req 4771 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: Found instance EAP TLS] of tls in methods list 2024-04-01 18:30:24,616 [Th 38 Req 4771 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: processing type tls instance EAP TLS] 2024-04-01 18:30:24,616 [Th 38 Req 4771 SessId R0000003b-01-660ad310] INFO RadiusServer.Radius - rlm_eap_tls: Initiate 2024-04-01 18:30:24,616 [Th 38 Req 4771 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap_tls: Requiring client certificate 2024-04-01 18:30:24,616 [Th 38 Req 4771 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap_tls: Start returned 1 2024-04-01 18:30:24,616 [Th 38 Req 4771 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: eap_compose returned 3 2024-04-01 18:30:24,616 [Th 38 Req 4771 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: eap_list_add EAP-State = 0x007800df009b00cda3120000a6953a1354ad2fce 2024-04-01 18:30:24,616 [Th 38 Req 4771 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallauthenticate]: module "svc_3056_eap" returns handled for request 4771 2024-04-01 18:30:24,616 [Th 38 Req 4771 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: leaving group svc_3056_eap (returns handled) for request 4771 2024-04-01 18:30:24,617 [Th 38 Req 4771 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - The request contains following state_items 2024-04-01 18:30:24,617 [Th 38 Req 4771 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Service-State = 0x00a2004a003b0003a3120000c1f91301d61330982cca5bcbc64bc7cf 2024-04-01 18:30:24,617 [Th 38 Req 4771 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - EAP-State = 0x007800df009b00cda3120000a6953a1354ad2fce 2024-04-01 18:30:24,617 [Th 38 Req 4771 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - The request contains following session_id 2024-04-01 18:30:24,617 [Th 38 Req 4771 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Session-Id = "R0000003b-01-660ad310" 2024-04-01 18:30:24,617 [Th 38 Req 4771 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - The request contains following session messages 2024-04-01 18:30:24,617 [Th 38 Req 4771 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - The request contains following persistent config items 2024-04-01 18:30:24,617 [Th 38 Req 4771 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - User-Password = 2024-04-01 18:30:24,617 [Th 38 Req 4771 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Persisted-User-Name = "MedoB_Training" 2024-04-01 18:30:24,617 [Th 38 Req 4771 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Authentication-Source = "Local:localhost" 2024-04-01 18:30:24,617 [Th 38 Req 4771 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Authentication-Source-Name = "Endpoints Repository]" 2024-04-01 18:30:24,617 [Th 38 Req 4771 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Authentication-Source-Id = 4 2024-04-01 18:30:24,617 [Th 38 Req 4771 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Policy Evaluation Status: 0, Request Status: 0, Error Code: 201 2024-04-01 18:30:24,617 [Th 38 Req 4771 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - reqst_node_alloc: pkt info ptr - 0x5c01d750, pkt info size 16 2024-04-01 18:30:24,617 [Th 38 Req 4771 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - reqst_node_alloc: updated pkt info - pkt # 1 2024-04-01 18:30:24,617 [Th 38 Req 4771 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Sending Access-Challenge of id 139 to 10.2.200.32 port 1812 2024-04-01 18:30:24,617 [Th 38 Req 4771 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - EAP-Message = 0x010300060d20 2024-04-01 18:30:24,617 [Th 38 Req 4771 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Message-Authenticator = 0x00000000000000000000000000000000 2024-04-01 18:30:24,617 [Th 38 Req 4771 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - State = 0x41506341616743324146696a45674141347356445845774146553979795259384533504963673d3d 2024-04-01 18:30:24,617 [Th 38 Req 4771 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - reqst_update_state node pkt info ptr 0x5c01d750, req cur pkt # 1, node cur pkt # 1 2024-04-01 18:30:24,617 [Th 38 Req 4771 SessId R0000003b-01-660ad310] INFO RadiusServer.Radius - reqst_update_state: Access-Challenge 139:88:48-4a-e9-c8-59-c4:APcAagC2AFijEgAA4sVDXEwAFU9yyRY8E3PIcg== 2024-04-01 18:30:24,617 [Th 38 Req 4771 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Finished request 4771 2024-04-01 18:30:24,617 [Th 38 Req 4771 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Going to the next request 2024-04-01 18:30:24,626 [Th 39 Req 4772] DEBUG RadiusServer.Radius - Session-Id = "R0000003b-01-660ad310" 2024-04-01 18:30:24,627 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Processing the authorize section of radiusd.conf 2024-04-01 18:30:24,627 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: entering group authorize for request 4772 2024-04-01 18:30:24,627 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallauthorize]: module "dacl" returns noop for request 4772 2024-04-01 18:30:24,627 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_service: The request has Service-State attribute 2024-04-01 18:30:24,627 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_service: svcreq_list_find Service-State = 0x00a2004a003b0003a3120000c1f91301d61330982cca5bcbc64bc7cf, Session-Id = "R0000003b-01-660ad310" 2024-04-01 18:30:24,627 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_service: Request found, released from the list 2024-04-01 18:30:24,627 [Th 39 Req 4772 SessId R0000003b-01-660ad310] INFO RadiusServer.Radius - rlm_service: The request was categorized into service "{ArubaOS SW} Wired Desktop DYN VLAN 802.1X" - 140:522:48-4a-e9-c8-59-c4 2024-04-01 18:30:24,627 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_service: Checking for username before "@" 2024-04-01 18:30:24,627 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_service: No delimiter. 2024-04-01 18:30:24,627 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_service: svcreq_list_add Service-State = 0x00c60023006c0020a4120000e0a0bd208dfcfdbe6c7d1f1019a37fb1, Session-Id = "R0000003b-01-660ad310" 2024-04-01 18:30:24,627 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallauthorize]: module "service" returns ok for request 4772 2024-04-01 18:30:24,627 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: leaving group authorize (returns ok) for request 4772 2024-04-01 18:30:24,627 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Found Autz-Type svc_{ArubaOS SW} Wired Desktop DYN VLAN 802.1X_3056 2024-04-01 18:30:24,627 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Processing the authorize section of radiusd.conf 2024-04-01 18:30:24,627 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: entering group svc_{ArubaOS SW} Wired Desktop DYN VLAN 802.1X_3056 for request 4772 2024-04-01 18:30:24,627 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: entering group for request 4772 2024-04-01 18:30:24,627 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: entering redundant-sticky group for request 4772 2024-04-01 18:30:24,627 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Redundant-sticky: Module authsrc_3001 is active 2024-04-01 18:30:24,627 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_ldap: Request contains authsrc items, returning 2024-04-01 18:30:24,627 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallauthorize]: module "authsrc_3001" returns notfound for request 4772 2024-04-01 18:30:24,627 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: redundant-sticky group returns notfound for request 4772 2024-04-01 18:30:24,627 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_sql (authsrc_4): Request contains authsrc items, returning 2024-04-01 18:30:24,627 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallauthorize]: module "authsrc_4" returns ok for request 4772 2024-04-01 18:30:24,627 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: leaving group (returns ok) for request 4772 2024-04-01 18:30:24,627 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: Deleting Proxy-To-Realm and Post-Proxy-Type attributes 2024-04-01 18:30:24,627 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: EAP packet type response id 3 length 90 2024-04-01 18:30:24,627 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: No EAP Start, assuming it's an on-going EAP conversation 2024-04-01 18:30:24,627 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallauthorize]: module "svc_3056_eap" returns updated for request 4772 2024-04-01 18:30:24,627 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_auth_check: Allowed authentication methods: svc_3056_eap 2024-04-01 18:30:24,627 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - radius: No MS Identity VP 2024-04-01 18:30:24,627 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_auth_check: allowed Authentication method svc_3056_eap set. 2024-04-01 18:30:24,627 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallauthorize]: module "svc_3056_auth_check" returns ok for request 4772 2024-04-01 18:30:24,627 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: leaving group svc_{ArubaOS SW} Wired Desktop DYN VLAN 802.1X_3056 (returns updated) for request 4772 2024-04-01 18:30:24,627 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rad_check_password: Found Auth-Type svc_3056_eap 2024-04-01 18:30:24,627 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - auth: type "svc_3056_eap" 2024-04-01 18:30:24,627 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Processing the authenticate section of radiusd.conf 2024-04-01 18:30:24,628 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: entering group svc_3056_eap for request 4772 2024-04-01 18:30:24,628 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: eaplist_find EAP-State = 0x007800df009b00cda3120000a6953a1354ad2fce 2024-04-01 18:30:24,628 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: Request found, released from the list 2024-04-01 18:30:24,628 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: EAP/tls 2024-04-01 18:30:24,628 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: processing type tls instance EAP TLS] 2024-04-01 18:30:24,628 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap_tls: Authenticate 2024-04-01 18:30:24,628 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap_tls: Request has authentication source Local:localhost 2024-04-01 18:30:24,628 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap_tls: processing TLS 2024-04-01 18:30:24,628 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap_tls: Server version 0 Peer Version 0 Choosing 0 2024-04-01 18:30:24,628 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - eaptls_verify returned 7 2024-04-01 18:30:24,628 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap_tls: Done initial handshake 2024-04-01 18:30:24,628 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap_tls: TLS packet length 89 flags 00 2024-04-01 18:30:24,628 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - (other): before SSL initialization 2024-04-01 18:30:24,628 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - TLS_accept: before SSL initialization 2024-04-01 18:30:24,628 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Ignoring cbtls_msg call with pseudo content type 256, version 0 2024-04-01 18:30:24,628 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - TLS_accept: before SSL initialization 2024-04-01 18:30:24,628 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap_tls: <<< Unknown TLS version length 004f] 2024-04-01 18:30:24,628 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - TLS_accept: SSLv3/TLS read client hello 2024-04-01 18:30:24,628 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Ignoring cbtls_msg call with pseudo content type 256, version 0 2024-04-01 18:30:24,628 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap_tls: >>> TLS 1.2 Handshake length 004a], ServerHello 2024-04-01 18:30:24,628 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - TLS_accept: SSLv3/TLS write server hello 2024-04-01 18:30:24,628 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Ignoring cbtls_msg call with pseudo content type 256, version 0 2024-04-01 18:30:24,628 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap_tls: >>> TLS 1.2 Handshake length 11f0], Certificate 2024-04-01 18:30:24,628 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - TLS_accept: SSLv3/TLS write certificate 2024-04-01 18:30:24,628 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Ignoring cbtls_msg call with pseudo content type 256, version 0 2024-04-01 18:30:24,628 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap_tls: >>> TLS 1.2 Handshake length 0c8e], CertificateRequest 2024-04-01 18:30:24,628 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - TLS_accept: SSLv3/TLS write certificate request 2024-04-01 18:30:24,628 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Ignoring cbtls_msg call with pseudo content type 256, version 0 2024-04-01 18:30:24,628 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap_tls: EAP-TLS-Version =1.2 2024-04-01 18:30:24,628 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap_tls: >>> TLS 1.2 Handshake length 0004], ServerHelloDone 2024-04-01 18:30:24,629 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - TLS_accept: SSLv3/TLS write server done 2024-04-01 18:30:24,629 [Th 39 Req 4772 SessId R0000003b-01-660ad310] INFO RadiusServer.Radius - TLS_accept:error in SSLv3/TLS write server done 2024-04-01 18:30:24,629 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - In SSL Handshake Phase 2024-04-01 18:30:24,629 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - In SSL Accept mode 2024-04-01 18:30:24,629 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - eaptls_process returned 13 2024-04-01 18:30:24,629 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: eap_compose returned 3 2024-04-01 18:30:24,629 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: eap_list_add EAP-State = 0x00a2008700490075a4120000140f878abd415851 2024-04-01 18:30:24,629 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallauthenticate]: module "svc_3056_eap" returns handled for request 4772 2024-04-01 18:30:24,629 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: leaving group svc_3056_eap (returns handled) for request 4772 2024-04-01 18:30:24,629 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - The request contains following state_items 2024-04-01 18:30:24,629 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Service-State = 0x00c60023006c0020a4120000e0a0bd208dfcfdbe6c7d1f1019a37fb1 2024-04-01 18:30:24,629 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - EAP-State = 0x00a2008700490075a4120000140f878abd415851 2024-04-01 18:30:24,629 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - The request contains following session_id 2024-04-01 18:30:24,629 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Session-Id = "R0000003b-01-660ad310" 2024-04-01 18:30:24,629 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - The request contains following session messages 2024-04-01 18:30:24,629 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - The request contains following persistent config items 2024-04-01 18:30:24,629 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - User-Password = 2024-04-01 18:30:24,629 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Persisted-User-Name = "MedoB_Training" 2024-04-01 18:30:24,629 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Authentication-Source = "Local:localhost" 2024-04-01 18:30:24,629 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Authentication-Source-Name = "Endpoints Repository]" 2024-04-01 18:30:24,629 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Authentication-Source-Id = 4 2024-04-01 18:30:24,629 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - EAP-TLS-Version = "1.2" 2024-04-01 18:30:24,629 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Policy Evaluation Status: 0, Request Status: 0, Error Code: 201 2024-04-01 18:30:24,629 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - reqst_node_alloc: pkt info ptr - 0x5c01d750, pkt info size 16 2024-04-01 18:30:24,629 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - reqst_node_alloc: updated pkt info - pkt # 2 2024-04-01 18:30:24,629 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Sending Access-Challenge of id 140 to 10.2.200.32 port 1812 2024-04-01 18:30:24,629 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - EAP-Message = 0x0104040a0dc000001ee0160303004a020000460303c652469d396fe4df1d85c7c0258d064986643ff3e9d2167ffb06778b149304012086bb63cef8f7ec34dc36c6724853031fce148d7312536a464261c68998823625003d0016030311f00b0011ec0011e900063c3082063830820420a00302010202132500005ee0252624e2154949bf000200005ee0300d06092a864886f70d01010b0500305531153013060a0992268993f22c64011916056c6f63616c311a3018060a0992268993f22c640119160a4d45444f4348454d49453120301e060355040313174d65646f6368656d69652049737375696e672043412031301e170d323430323035303831 2024-04-01 18:30:24,629 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - EAP-Message = 0x3531315a170d3236303230343038313531315a3073310b3009060355040613024359310b30090603550408130243593110300e060355040713074c656d65736f7331173015060355040a130e4d65646f6368656d6965204c7464310b3009060355040b13024954311f301d0603550403131663796e61632e6d65646f6368656d69652e6c6f63616c30820122300d06092a864886f70d01010105000382010f003082010a0282010100c3728aa9f7fc4cabae0802d4e8a3decc802c71e3a2bd141668a802cd1d201ad035531afef17254c3fda6304e453cded45cc89871dc8e787b31a06e7190baf18bfda334b7ff1c84ccc12bc0ae388c871651b73039 2024-04-01 18:30:24,630 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - EAP-Message = 0x882fc5c6b5711d02b1b82ea7d9689680b52e04fa78fada5ffbf09d5a10f265e932aeb9842dc82e71e31451138ce58118bf5052cad49cc56478e66bb7496533d788aa3ebd012b30614feb0cedea7fd39409dda1830638a938f7055499b3536f3bb61b8a0a91a3ad6e6279d09c939c950ca5ba3560185ed26bedd14e13656613403f5bc4a5da2ec782f7668a3af300e60259a1f858953de6d766cce7cdc3c64a214c2b3a280da4d5593d64566d0203010001a38201e1308201dd30130603551d25040c300a06082b06010505070301301d0603551d0e041604144c9e41ee3f16fde5b3b64b5ef7cbd6f97aa20c7030630603551d11045c305a821763796e 2024-04-01 18:30:24,630 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - EAP-Message = 0x6163312e6d65646f6368656d69652e6c6f63616c821764726e6163312e6d65646f6368656d69652e6c6f63616c821463796e61632e6d65646f6368656d69652e636f6d87040a02003c87040a02003d87040a02003e301f0603551d230418301680148b9a014961727b038b8f0783d3cf0dc3b155ca6930520603551d1f044b30493047a045a0438641687474703a2f2f706b692e6d65646f6368656d69652e636f6d2f63657274732f4d65646f6368656d696525323049737375696e672532304341253230312e63726c306506082b0601050507010104593057305506082b060105050730028649687474703a2f2f706b692e6d65646f6368656d6965 2024-04-01 18:30:24,630 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - EAP-Message = 0x2e636f6d2f63657274732f323031385f4d65646f6368 2024-04-01 18:30:24,630 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Message-Authenticator = 0x00000000000000000000000000000000 2024-04-01 18:30:24,630 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - State = 0x414b6741594143504145476b456741416a4a75655a637550786748304779304572334a6f71413d3d 2024-04-01 18:30:24,630 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - reqst_update_state node pkt info ptr 0x5c01d750, req cur pkt # 2, node cur pkt # 2 2024-04-01 18:30:24,630 [Th 39 Req 4772 SessId R0000003b-01-660ad310] INFO RadiusServer.Radius - reqst_update_state: Access-Challenge 140:1124:48-4a-e9-c8-59-c4:AKgAYACPAEGkEgAAjJueZcuPxgH0Gy0Er3JoqA== 2024-04-01 18:30:24,630 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Finished request 4772 2024-04-01 18:30:24,630 [Th 39 Req 4772 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Going to the next request 2024-04-01 18:30:24,634 [Th 44 Req 4773] DEBUG RadiusServer.Radius - Session-Id = "R0000003b-01-660ad310" 2024-04-01 18:30:24,634 [Th 44 Req 4773 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Processing the authorize section of radiusd.conf 2024-04-01 18:30:24,634 [Th 44 Req 4773 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: entering group authorize for request 4773 2024-04-01 18:30:24,634 [Th 44 Req 4773 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallauthorize]: module "dacl" returns noop for request 4773 2024-04-01 18:30:24,634 [Th 44 Req 4773 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_service: The request has Service-State attribute 2024-04-01 18:30:24,634 [Th 44 Req 4773 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_service: svcreq_list_find Service-State = 0x00c60023006c0020a4120000e0a0bd208dfcfdbe6c7d1f1019a37fb1, Session-Id = "R0000003b-01-660ad310" 2024-04-01 18:30:24,634 [Th 44 Req 4773 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_service: Request found, released from the list 2024-04-01 18:30:24,634 [Th 44 Req 4773 SessId R0000003b-01-660ad310] INFO RadiusServer.Radius - rlm_service: The request was categorized into service "{ArubaOS SW} Wired Desktop DYN VLAN 802.1X" - 141:438:48-4a-e9-c8-59-c4 2024-04-01 18:30:24,634 [Th 44 Req 4773 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_service: Checking for username before "@" 2024-04-01 18:30:24,634 [Th 44 Req 4773 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_service: No delimiter. 2024-04-01 18:30:24,634 [Th 44 Req 4773 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_service: svcreq_list_add Service-State = 0x0078000d0066008ba5120000c905a8a4a8b5225a13c577aa8aea29a8, Session-Id = "R0000003b-01-660ad310" 2024-04-01 18:30:24,634 [Th 44 Req 4773 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallauthorize]: module "service" returns ok for request 4773 2024-04-01 18:30:24,634 [Th 44 Req 4773 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: leaving group authorize (returns ok) for request 4773 2024-04-01 18:30:24,634 [Th 44 Req 4773 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Found Autz-Type svc_{ArubaOS SW} Wired Desktop DYN VLAN 802.1X_3056 2024-04-01 18:30:24,634 [Th 44 Req 4773 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Processing the authorize section of radiusd.conf 2024-04-01 18:30:24,634 [Th 44 Req 4773 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: entering group svc_{ArubaOS SW} Wired Desktop DYN VLAN 802.1X_3056 for request 4773 2024-04-01 18:30:24,634 [Th 44 Req 4773 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: entering group for request 4773 2024-04-01 18:30:24,634 [Th 44 Req 4773 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: entering redundant-sticky group for request 4773 2024-04-01 18:30:24,634 [Th 44 Req 4773 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Redundant-sticky: Module authsrc_3001 is active 2024-04-01 18:30:24,634 [Th 44 Req 4773 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_ldap: Request contains authsrc items, returning 2024-04-01 18:30:24,634 [Th 44 Req 4773 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallauthorize]: module "authsrc_3001" returns notfound for request 4773 2024-04-01 18:30:24,634 [Th 44 Req 4773 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: redundant-sticky group returns notfound for request 4773 2024-04-01 18:30:24,634 [Th 44 Req 4773 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_sql (authsrc_4): Request contains authsrc items, returning 2024-04-01 18:30:24,634 [Th 44 Req 4773 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallauthorize]: module "authsrc_4" returns ok for request 4773 2024-04-01 18:30:24,634 [Th 44 Req 4773 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: leaving group (returns ok) for request 4773 2024-04-01 18:30:24,634 [Th 44 Req 4773 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: Deleting Proxy-To-Realm and Post-Proxy-Type attributes 2024-04-01 18:30:24,634 [Th 44 Req 4773 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: EAP packet type response id 4 length 6 2024-04-01 18:30:24,634 [Th 44 Req 4773 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: No EAP Start, assuming it's an on-going EAP conversation 2024-04-01 18:30:24,635 [Th 44 Req 4773 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallauthorize]: module "svc_3056_eap" returns updated for request 4773 2024-04-01 18:30:24,635 [Th 44 Req 4773 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_auth_check: Allowed authentication methods: svc_3056_eap 2024-04-01 18:30:24,635 [Th 44 Req 4773 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - radius: No MS Identity VP 2024-04-01 18:30:24,635 [Th 44 Req 4773 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_auth_check: allowed Authentication method svc_3056_eap set. 2024-04-01 18:30:24,635 [Th 44 Req 4773 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallauthorize]: module "svc_3056_auth_check" returns ok for request 4773 2024-04-01 18:30:24,635 [Th 44 Req 4773 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: leaving group svc_{ArubaOS SW} Wired Desktop DYN VLAN 802.1X_3056 (returns updated) for request 4773 2024-04-01 18:30:24,635 [Th 44 Req 4773 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rad_check_password: Found Auth-Type svc_3056_eap 2024-04-01 18:30:24,635 [Th 44 Req 4773 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - auth: type "svc_3056_eap" 2024-04-01 18:30:24,635 [Th 44 Req 4773 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Processing the authenticate section of radiusd.conf 2024-04-01 18:30:24,635 [Th 44 Req 4773 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: entering group svc_3056_eap for request 4773 2024-04-01 18:30:24,635 [Th 44 Req 4773 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: eaplist_find EAP-State = 0x00a2008700490075a4120000140f878abd415851 2024-04-01 18:30:24,635 [Th 44 Req 4773 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: Request found, released from the list 2024-04-01 18:30:24,635 [Th 44 Req 4773 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: EAP/tls 2024-04-01 18:30:24,635 [Th 44 Req 4773 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: processing type tls instance EAP TLS] 2024-04-01 18:30:24,635 [Th 44 Req 4773 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap_tls: Authenticate 2024-04-01 18:30:24,635 [Th 44 Req 4773 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap_tls: Request has authentication source Local:localhost 2024-04-01 18:30:24,635 [Th 44 Req 4773 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap_tls: processing TLS 2024-04-01 18:30:24,635 [Th 44 Req 4773 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap_tls: Received EAP-TLS ACK message 2024-04-01 18:30:24,635 [Th 44 Req 4773 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap_tls: ack handshake fragment handler 2024-04-01 18:30:24,635 [Th 44 Req 4773 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - eaptls_verify returned 1 2024-04-01 18:30:24,635 [Th 44 Req 4773 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - eaptls_process returned 13 2024-04-01 18:30:24,635 [Th 44 Req 4773 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: eap_compose returned 3 2024-04-01 18:30:24,635 [Th 44 Req 4773 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: eap_list_add EAP-State = 0x00330070002b0012a51200001da638b0c72918c3 2024-04-01 18:30:24,635 [Th 44 Req 4773 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallauthenticate]: module "svc_3056_eap" returns handled for request 4773 2024-04-01 18:30:24,635 [Th 44 Req 4773 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: leaving group svc_3056_eap (returns handled) for request 4773 2024-04-01 18:30:24,635 [Th 44 Req 4773 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - The request contains following state_items 2024-04-01 18:30:24,635 [Th 44 Req 4773 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Service-State = 0x0078000d0066008ba5120000c905a8a4a8b5225a13c577aa8aea29a8 2024-04-01 18:30:24,635 [Th 44 Req 4773 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - EAP-State = 0x00330070002b0012a51200001da638b0c72918c3 2024-04-01 18:30:24,635 [Th 44 Req 4773 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - The request contains following session_id 2024-04-01 18:30:24,635 [Th 44 Req 4773 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Session-Id = "R0000003b-01-660ad310" 2024-04-01 18:30:24,635 [Th 44 Req 4773 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - The request contains following session messages 2024-04-01 18:30:24,635 [Th 44 Req 4773 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - The request contains following persistent config items 2024-04-01 18:30:24,635 [Th 44 Req 4773 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - User-Password = 2024-04-01 18:30:24,635 [Th 44 Req 4773 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Persisted-User-Name = "MedoB_Training" 2024-04-01 18:30:24,635 [Th 44 Req 4773 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Authentication-Source = "Local:localhost" 2024-04-01 18:30:24,635 [Th 44 Req 4773 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Authentication-Source-Name = "Endpoints Repository]" 2024-04-01 18:30:24,635 [Th 44 Req 4773 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Authentication-Source-Id = 4 2024-04-01 18:30:24,635 [Th 44 Req 4773 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - EAP-TLS-Version = "1.2" 2024-04-01 18:30:24,635 [Th 44 Req 4773 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Policy Evaluation Status: 0, Request Status: 0, Error Code: 201 2024-04-01 18:30:24,635 [Th 44 Req 4773 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - reqst_node_alloc: pkt info ptr - 0x5c01d750, pkt info size 16 2024-04-01 18:30:24,635 [Th 44 Req 4773 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - reqst_node_alloc: updated pkt info - pkt # 3 2024-04-01 18:30:24,635 [Th 44 Req 4773 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Sending Access-Challenge of id 141 to 10.2.200.32 port 1812 2024-04-01 18:30:24,636 [Th 44 Req 4773 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - EAP-Message = 0x010504060d40656d696525323049737375696e672532304341253230312832292e637274300b0603551d0f0404030205a0303c06092b0601040182371507042f302d06252b060104018237150883c0e239a6bc1b82a5933d90a9048498a22e816587a3c47485f6c367020164020105301b06092b060104018237150a040e300c300a06082b06010505070301300d06092a864886f70d01010b050003820201002fe5ebcc3b175cf385b643cca4155b66a3df076d3273db282bcd32850fb926c430dda5cc067c42d3cc74bbaf3e5f91553c50cc295c9f84aacd7b79b64495084501ac7da718ed4616a72b66dd3964263cbe2900f2091f1c34ea3b1fa702 2024-04-01 18:30:24,636 [Th 44 Req 4773 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - EAP-Message = 0xf60eb62af0cccb6cebe845a67c52b12f743eb40d44be0af3f8e095e7eb153e0864e39bed494a2ae7fbe4072276ef98b1e2eae68e86796178faf51a349b55063cf0411c074735ed6335b3db901e9ec1b00f87a7994ee3f73858cff6aa9b16bc207b95d6628076e33aa3b9a59aa1300dcd41d297591a758c75dd7d2e68ee87dfc1b33c6e8f79649eff487a64c4328dbdd4f7b7a05becbeeb17dc3e0ac1bb8074adebc16448b46c2c9db7ad0e82667485806ae9fbdff6efb8690080f1f884affd3a7862ecec004821fa209f2bbe1c1e7aebf38c37f54e470373d686f0cc2e6aafb2c9b3a5ae921a73fdfb01a4ddc827e0ec1961b53b95ef6d8fe0b6b4383f 2024-04-01 18:30:24,636 [Th 44 Req 4773 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - EAP-Message = 0x11f838f9d5c90b2c5e6d0cd544d52619012d7f04caba4bcb8ee260add81b85293840db38dead28384564cd386825511390d2bf1099baace65733e2effc0374d22b083177b4cb38f2207a1d2aa1ea09140cbe545376bbcb7fed22f9efbdec0bf785e2ad66851d87d01fdfec04b7866a3f57d3a0d15271274cfed041ca9eaa41141dcf1bec406c710deb215b8dc97e3a218d6ac2f8e795ce762f229313b44894b63498cce103ca000666308206623082044aa00302010202131200000007bbc257e38e38cd8d000100000007300d06092a864886f70d01010b0500301d311b3019060355040313124d65646f6368656d696520526f6f74204341301e170d 2024-04-01 18:30:24,636 [Th 44 Req 4773 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - EAP-Message = 0x3234303230353037353333305a170d3239303230353038303333305a305531153013060a0992268993f22c64011916056c6f63616c311a3018060a0992268993f22c640119160a4d45444f4348454d49453120301e060355040313174d65646f6368656d69652049737375696e67204341203130820222300d06092a864886f70d01010105000382020f003082020a0282020100ad9a77e1d5f0ada543a11097142a7a058e6cb3688358df2d4ddcb9340ae0491a3bf0c63208a4954b117edb083af6031d24d7260a8577401792134f512e394cdb144390172bc45cd3bdda60a981f2b27577417cece448e28c23299b6469de555812ef4ac91f3ef5cfb4 2024-04-01 18:30:24,636 [Th 44 Req 4773 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - EAP-Message = 0xbdc02b84280d0694d8d3fa1abae119a31b69 2024-04-01 18:30:24,636 [Th 44 Req 4773 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Message-Authenticator = 0x00000000000000000000000000000000 2024-04-01 18:30:24,636 [Th 44 Req 4773 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - State = 0x414938415a6743464150326c45674141596b4945367959674566514d48535466574a4a514d413d3d 2024-04-01 18:30:24,636 [Th 44 Req 4773 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - reqst_update_state node pkt info ptr 0x5c01d750, req cur pkt # 3, node cur pkt # 3 2024-04-01 18:30:24,636 [Th 44 Req 4773 SessId R0000003b-01-660ad310] INFO RadiusServer.Radius - reqst_update_state: Access-Challenge 141:1120:48-4a-e9-c8-59-c4:AI8AZgCFAP2lEgAAYkIE6yYgEfQMHSTfWJJQMA== 2024-04-01 18:30:24,636 [Th 44 Req 4773 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Finished request 4773 2024-04-01 18:30:24,636 [Th 44 Req 4773 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Going to the next request 2024-04-01 18:30:24,639 [Th 42 Req 4774] DEBUG RadiusServer.Radius - Session-Id = "R0000003b-01-660ad310" 2024-04-01 18:30:24,640 [Th 42 Req 4774 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Processing the authorize section of radiusd.conf 2024-04-01 18:30:24,640 [Th 42 Req 4774 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: entering group authorize for request 4774 2024-04-01 18:30:24,640 [Th 42 Req 4774 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallauthorize]: module "dacl" returns noop for request 4774 2024-04-01 18:30:24,640 [Th 42 Req 4774 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_service: The request has Service-State attribute 2024-04-01 18:30:24,640 [Th 42 Req 4774 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_service: svcreq_list_find Service-State = 0x0078000d0066008ba5120000c905a8a4a8b5225a13c577aa8aea29a8, Session-Id = "R0000003b-01-660ad310" 2024-04-01 18:30:24,640 [Th 42 Req 4774 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_service: Request found, released from the list 2024-04-01 18:30:24,640 [Th 42 Req 4774 SessId R0000003b-01-660ad310] INFO RadiusServer.Radius - rlm_service: The request was categorized into service "{ArubaOS SW} Wired Desktop DYN VLAN 802.1X" - 142:438:48-4a-e9-c8-59-c4 2024-04-01 18:30:24,640 [Th 42 Req 4774 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_service: Checking for username before "@" 2024-04-01 18:30:24,640 [Th 42 Req 4774 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_service: No delimiter. 2024-04-01 18:30:24,640 [Th 42 Req 4774 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_service: svcreq_list_add Service-State = 0x007c00ce00be0034a6120000896e6ad39499528d0939e1aa6fb3b234, Session-Id = "R0000003b-01-660ad310" 2024-04-01 18:30:24,640 [Th 42 Req 4774 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallauthorize]: module "service" returns ok for request 4774 2024-04-01 18:30:24,640 [Th 42 Req 4774 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: leaving group authorize (returns ok) for request 4774 2024-04-01 18:30:24,640 [Th 42 Req 4774 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Found Autz-Type svc_{ArubaOS SW} Wired Desktop DYN VLAN 802.1X_3056 2024-04-01 18:30:24,640 [Th 42 Req 4774 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Processing the authorize section of radiusd.conf 2024-04-01 18:30:24,640 [Th 42 Req 4774 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: entering group svc_{ArubaOS SW} Wired Desktop DYN VLAN 802.1X_3056 for request 4774 2024-04-01 18:30:24,640 [Th 42 Req 4774 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: entering group for request 4774 2024-04-01 18:30:24,640 [Th 42 Req 4774 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: entering redundant-sticky group for request 4774 2024-04-01 18:30:24,640 [Th 42 Req 4774 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Redundant-sticky: Module authsrc_3001 is active 2024-04-01 18:30:24,640 [Th 42 Req 4774 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_ldap: Request contains authsrc items, returning 2024-04-01 18:30:24,640 [Th 42 Req 4774 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallauthorize]: module "authsrc_3001" returns notfound for request 4774 2024-04-01 18:30:24,640 [Th 42 Req 4774 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: redundant-sticky group returns notfound for request 4774 2024-04-01 18:30:24,640 [Th 42 Req 4774 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_sql (authsrc_4): Request contains authsrc items, returning 2024-04-01 18:30:24,640 [Th 42 Req 4774 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallauthorize]: module "authsrc_4" returns ok for request 4774 2024-04-01 18:30:24,640 [Th 42 Req 4774 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: leaving group (returns ok) for request 4774 2024-04-01 18:30:24,640 [Th 42 Req 4774 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: Deleting Proxy-To-Realm and Post-Proxy-Type attributes 2024-04-01 18:30:24,640 [Th 42 Req 4774 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: EAP packet type response id 5 length 6 2024-04-01 18:30:24,640 [Th 42 Req 4774 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: No EAP Start, assuming it's an on-going EAP conversation 2024-04-01 18:30:24,641 [Th 42 Req 4774 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallauthorize]: module "svc_3056_eap" returns updated for request 4774 2024-04-01 18:30:24,641 [Th 42 Req 4774 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_auth_check: Allowed authentication methods: svc_3056_eap 2024-04-01 18:30:24,641 [Th 42 Req 4774 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - radius: No MS Identity VP 2024-04-01 18:30:24,641 [Th 42 Req 4774 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_auth_check: allowed Authentication method svc_3056_eap set. 2024-04-01 18:30:24,641 [Th 42 Req 4774 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallauthorize]: module "svc_3056_auth_check" returns ok for request 4774 2024-04-01 18:30:24,641 [Th 42 Req 4774 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: leaving group svc_{ArubaOS SW} Wired Desktop DYN VLAN 802.1X_3056 (returns updated) for request 4774 2024-04-01 18:30:24,641 [Th 42 Req 4774 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rad_check_password: Found Auth-Type svc_3056_eap 2024-04-01 18:30:24,641 [Th 42 Req 4774 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - auth: type "svc_3056_eap" 2024-04-01 18:30:24,641 [Th 42 Req 4774 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Processing the authenticate section of radiusd.conf 2024-04-01 18:30:24,641 [Th 42 Req 4774 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: entering group svc_3056_eap for request 4774 2024-04-01 18:30:24,641 [Th 42 Req 4774 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: eaplist_find EAP-State = 0x00330070002b0012a51200001da638b0c72918c3 2024-04-01 18:30:24,641 [Th 42 Req 4774 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: Request found, released from the list 2024-04-01 18:30:24,641 [Th 42 Req 4774 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: EAP/tls 2024-04-01 18:30:24,641 [Th 42 Req 4774 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: processing type tls instance EAP TLS] 2024-04-01 18:30:24,641 [Th 42 Req 4774 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap_tls: Authenticate 2024-04-01 18:30:24,641 [Th 42 Req 4774 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap_tls: Request has authentication source Local:localhost 2024-04-01 18:30:24,641 [Th 42 Req 4774 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap_tls: processing TLS 2024-04-01 18:30:24,641 [Th 42 Req 4774 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap_tls: Received EAP-TLS ACK message 2024-04-01 18:30:24,641 [Th 42 Req 4774 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap_tls: ack handshake fragment handler 2024-04-01 18:30:24,641 [Th 42 Req 4774 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - eaptls_verify returned 1 2024-04-01 18:30:24,641 [Th 42 Req 4774 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - eaptls_process returned 13 2024-04-01 18:30:24,641 [Th 42 Req 4774 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: eap_compose returned 3 2024-04-01 18:30:24,641 [Th 42 Req 4774 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: eap_list_add EAP-State = 0x00700055008d00e7a6120000e9e177cce9cf962f 2024-04-01 18:30:24,641 [Th 42 Req 4774 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallauthenticate]: module "svc_3056_eap" returns handled for request 4774 2024-04-01 18:30:24,641 [Th 42 Req 4774 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: leaving group svc_3056_eap (returns handled) for request 4774 2024-04-01 18:30:24,641 [Th 42 Req 4774 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - The request contains following state_items 2024-04-01 18:30:24,641 [Th 42 Req 4774 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Service-State = 0x007c00ce00be0034a6120000896e6ad39499528d0939e1aa6fb3b234 2024-04-01 18:30:24,641 [Th 42 Req 4774 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - EAP-State = 0x00700055008d00e7a6120000e9e177cce9cf962f 2024-04-01 18:30:24,641 [Th 42 Req 4774 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - The request contains following session_id 2024-04-01 18:30:24,641 [Th 42 Req 4774 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Session-Id = "R0000003b-01-660ad310" 2024-04-01 18:30:24,641 [Th 42 Req 4774 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - The request contains following session messages 2024-04-01 18:30:24,642 [Th 42 Req 4774 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - The request contains following persistent config items 2024-04-01 18:30:24,642 [Th 42 Req 4774 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - User-Password = 2024-04-01 18:30:24,642 [Th 42 Req 4774 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Persisted-User-Name = "MedoB_Training" 2024-04-01 18:30:24,642 [Th 42 Req 4774 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Authentication-Source = "Local:localhost" 2024-04-01 18:30:24,642 [Th 42 Req 4774 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Authentication-Source-Name = "Endpoints Repository]" 2024-04-01 18:30:24,642 [Th 42 Req 4774 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Authentication-Source-Id = 4 2024-04-01 18:30:24,642 [Th 42 Req 4774 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - EAP-TLS-Version = "1.2" 2024-04-01 18:30:24,642 [Th 42 Req 4774 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Policy Evaluation Status: 0, Request Status: 0, Error Code: 201 2024-04-01 18:30:24,642 [Th 42 Req 4774 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - reqst_node_alloc: pkt info ptr - 0x5c01d750, pkt info size 16 2024-04-01 18:30:24,642 [Th 42 Req 4774 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - reqst_node_alloc: updated pkt info - pkt # 4 2024-04-01 18:30:24,642 [Th 42 Req 4774 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Sending Access-Challenge of id 142 to 10.2.200.32 port 1812 2024-04-01 18:30:24,642 [Th 42 Req 4774 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - EAP-Message = 0x010604060d40c887908f749c5f554941ac1fe64b49d0e630842127ea841c50e5a2f2d2f1e4e01d4102c3d9f801edcd56a22fb67ed038fe8843fe04ecced562d124722808375e8a8f739d49e56f2286131c2c3d5a79e6834f75beaa314e0dc87db57f87963e6b20018c931de5e333137c9614ad711c3af7420d42fe6852f0ec09ebc8171c525777f308aa4c3d30c3f6a0aee397163a0ff4ad891ab18bb09def181039d9186f8a8b6c898b4449dab18cdfde5dc20a2b50b3d979758c64c9bef81d0591abc60584d22d8bdc9e11f6dd781106472093b30bc44a6180f376049192f4c222fb1021258ea4def4ec0786b6bf2dbd916c910082ee7452e1e03220 2024-04-01 18:30:24,642 [Th 42 Req 4774 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - EAP-Message = 0x393dcc5163db977846032dc5809115bfcc8126c80a8603b3d4b0f186b4f5769f266325c7eeece745482d4c08a644fe9a42f4ed0cd6a36a4b70e3ab6405651e33105399a09d16d332e35ab1ae82b9cecab440f33c7663fd9a5c83d9d0dae507b124e17a33d31e0a3b5197dbd806ee7727d931b0979c1a615aaea8e5f69245a7efd5d64c90a1ccf5a2f73ead0fc89d0203010001a38201613082015d301006092b06010401823715010403020102302306092b0601040182371502041604142c9c5ab09fc1a18034d17d874bbbc505d2b62b8f301d0603551d0e041604148b9a014961727b038b8f0783d3cf0dc3b155ca69301906092b06010401823714 2024-04-01 18:30:24,642 [Th 42 Req 4774 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - EAP-Message = 0x02040c1e0a00530075006200430041300b0603551d0f040403020186300f0603551d130101ff040530030101ff301f0603551d23041830168014fbc7ada7499ab3a0ef70214bb9ff60fc8bf7ab20304b0603551d1f044430423040a03ea03c863a687474703a2f2f706b692e6d65646f6368656d69652e636f6d2f63657274732f4d65646f6368656d6965253230526f6f7425323043412e63726c305e06082b0601050507010104523050304e06082b060105050730028642687474703a2f2f706b692e6d65646f6368656d69652e636f6d2f63657274732f323031385f4d65646f6368656d6965253230526f6f7425323043412831292e637274300d 2024-04-01 18:30:24,642 [Th 42 Req 4774 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - EAP-Message = 0x06092a864886f70d01010b05000382020100b2292adb8e6c776d913b50ffb6732495859f4a10d16ff8c3411cfe3754ab802759cfb93ffaa23fb79b489850c39c3f50ee26ca82f7ac44ca9bba4e92e8b2ce3bad7df860154ef6ade2f6ef59e751b2a3beb8abb5016823c2b85df827a4937bef7ff8c44ca71fb2145a0a8a99ffc424f24e1ac403208d32ce60310ae1af9a5700958e896fbc5d0a2abf20d32392c3a84d4033ec531a53c134fd5142331db7a2ef3d5b49cef4937a99d349f49fc45e7514ac2a1aced1fe2fa08353b4534d910b6ffa22657d923e4765302066790e02572304c4ca624d4cfc560ba52de4e7dd3c009bd8cdc9aca2925ca8d896 2024-04-01 18:30:24,642 [Th 42 Req 4774 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - EAP-Message = 0x845a71b11c35e68319925a9b1c4f13ba7e89 2024-04-01 18:30:24,642 [Th 42 Req 4774 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Message-Authenticator = 0x00000000000000000000000000000000 2024-04-01 18:30:24,642 [Th 42 Req 4774 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - State = 0x41434141474142714148366d45674141696b575139786a3849562f4e6432737a2f77622f31673d3d 2024-04-01 18:30:24,642 [Th 42 Req 4774 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - reqst_update_state node pkt info ptr 0x5c01d750, req cur pkt # 4, node cur pkt # 4 2024-04-01 18:30:24,642 [Th 42 Req 4774 SessId R0000003b-01-660ad310] INFO RadiusServer.Radius - reqst_update_state: Access-Challenge 142:1120:48-4a-e9-c8-59-c4:ACAAGABqAH6mEgAAikWQ9xj8IV/Nd2sz/wb/1g== 2024-04-01 18:30:24,642 [Th 42 Req 4774 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Finished request 4774 2024-04-01 18:30:24,642 [Th 42 Req 4774 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Going to the next request 2024-04-01 18:30:24,645 [Th 40 Req 4775] DEBUG RadiusServer.Radius - Session-Id = "R0000003b-01-660ad310" 2024-04-01 18:30:24,645 [Th 40 Req 4775 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Processing the authorize section of radiusd.conf 2024-04-01 18:30:24,645 [Th 40 Req 4775 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: entering group authorize for request 4775 2024-04-01 18:30:24,645 [Th 40 Req 4775 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallauthorize]: module "dacl" returns noop for request 4775 2024-04-01 18:30:24,645 [Th 40 Req 4775 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_service: The request has Service-State attribute 2024-04-01 18:30:24,645 [Th 40 Req 4775 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_service: svcreq_list_find Service-State = 0x007c00ce00be0034a6120000896e6ad39499528d0939e1aa6fb3b234, Session-Id = "R0000003b-01-660ad310" 2024-04-01 18:30:24,645 [Th 40 Req 4775 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_service: Request found, released from the list 2024-04-01 18:30:24,645 [Th 40 Req 4775 SessId R0000003b-01-660ad310] INFO RadiusServer.Radius - rlm_service: The request was categorized into service "{ArubaOS SW} Wired Desktop DYN VLAN 802.1X" - 143:438:48-4a-e9-c8-59-c4 2024-04-01 18:30:24,645 [Th 40 Req 4775 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_service: Checking for username before "@" 2024-04-01 18:30:24,645 [Th 40 Req 4775 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_service: No delimiter. 2024-04-01 18:30:24,645 [Th 40 Req 4775 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_service: svcreq_list_add Service-State = 0x00ee0024009300c4a71200004cdbd2a511a387c4bf4d56786a0f1343, Session-Id = "R0000003b-01-660ad310" 2024-04-01 18:30:24,645 [Th 40 Req 4775 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallauthorize]: module "service" returns ok for request 4775 2024-04-01 18:30:24,645 [Th 40 Req 4775 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: leaving group authorize (returns ok) for request 4775 2024-04-01 18:30:24,645 [Th 40 Req 4775 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Found Autz-Type svc_{ArubaOS SW} Wired Desktop DYN VLAN 802.1X_3056 2024-04-01 18:30:24,645 [Th 40 Req 4775 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Processing the authorize section of radiusd.conf 2024-04-01 18:30:24,645 [Th 40 Req 4775 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: entering group svc_{ArubaOS SW} Wired Desktop DYN VLAN 802.1X_3056 for request 4775 2024-04-01 18:30:24,645 [Th 40 Req 4775 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: entering group for request 4775 2024-04-01 18:30:24,645 [Th 40 Req 4775 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: entering redundant-sticky group for request 4775 2024-04-01 18:30:24,645 [Th 40 Req 4775 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Redundant-sticky: Module authsrc_3001 is active 2024-04-01 18:30:24,645 [Th 40 Req 4775 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_ldap: Request contains authsrc items, returning 2024-04-01 18:30:24,645 [Th 40 Req 4775 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallauthorize]: module "authsrc_3001" returns notfound for request 4775 2024-04-01 18:30:24,645 [Th 40 Req 4775 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: redundant-sticky group returns notfound for request 4775 2024-04-01 18:30:24,645 [Th 40 Req 4775 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_sql (authsrc_4): Request contains authsrc items, returning 2024-04-01 18:30:24,646 [Th 40 Req 4775 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallauthorize]: module "authsrc_4" returns ok for request 4775 2024-04-01 18:30:24,646 [Th 40 Req 4775 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: leaving group (returns ok) for request 4775 2024-04-01 18:30:24,646 [Th 40 Req 4775 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: Deleting Proxy-To-Realm and Post-Proxy-Type attributes 2024-04-01 18:30:24,646 [Th 40 Req 4775 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: EAP packet type response id 6 length 6 2024-04-01 18:30:24,646 [Th 40 Req 4775 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: No EAP Start, assuming it's an on-going EAP conversation 2024-04-01 18:30:24,646 [Th 40 Req 4775 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallauthorize]: module "svc_3056_eap" returns updated for request 4775 2024-04-01 18:30:24,646 [Th 40 Req 4775 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_auth_check: Allowed authentication methods: svc_3056_eap 2024-04-01 18:30:24,646 [Th 40 Req 4775 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - radius: No MS Identity VP 2024-04-01 18:30:24,646 [Th 40 Req 4775 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_auth_check: allowed Authentication method svc_3056_eap set. 2024-04-01 18:30:24,646 [Th 40 Req 4775 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallauthorize]: module "svc_3056_auth_check" returns ok for request 4775 2024-04-01 18:30:24,646 [Th 40 Req 4775 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: leaving group svc_{ArubaOS SW} Wired Desktop DYN VLAN 802.1X_3056 (returns updated) for request 4775 2024-04-01 18:30:24,646 [Th 40 Req 4775 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rad_check_password: Found Auth-Type svc_3056_eap 2024-04-01 18:30:24,646 [Th 40 Req 4775 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - auth: type "svc_3056_eap" 2024-04-01 18:30:24,646 [Th 40 Req 4775 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Processing the authenticate section of radiusd.conf 2024-04-01 18:30:24,646 [Th 40 Req 4775 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: entering group svc_3056_eap for request 4775 2024-04-01 18:30:24,646 [Th 40 Req 4775 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: eaplist_find EAP-State = 0x00700055008d00e7a6120000e9e177cce9cf962f 2024-04-01 18:30:24,646 [Th 40 Req 4775 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: Request found, released from the list 2024-04-01 18:30:24,646 [Th 40 Req 4775 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: EAP/tls 2024-04-01 18:30:24,646 [Th 40 Req 4775 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: processing type tls instance EAP TLS] 2024-04-01 18:30:24,646 [Th 40 Req 4775 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap_tls: Authenticate 2024-04-01 18:30:24,646 [Th 40 Req 4775 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap_tls: Request has authentication source Local:localhost 2024-04-01 18:30:24,646 [Th 40 Req 4775 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap_tls: processing TLS 2024-04-01 18:30:24,646 [Th 40 Req 4775 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap_tls: Received EAP-TLS ACK message 2024-04-01 18:30:24,646 [Th 40 Req 4775 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap_tls: ack handshake fragment handler 2024-04-01 18:30:24,646 [Th 40 Req 4775 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - eaptls_verify returned 1 2024-04-01 18:30:24,646 [Th 40 Req 4775 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - eaptls_process returned 13 2024-04-01 18:30:24,646 [Th 40 Req 4775 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: eap_compose returned 3 2024-04-01 18:30:24,646 [Th 40 Req 4775 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: eap_list_add EAP-State = 0x00c0000f00da008fa712000032dab9cf056e0151 2024-04-01 18:30:24,646 [Th 40 Req 4775 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallauthenticate]: module "svc_3056_eap" returns handled for request 4775 2024-04-01 18:30:24,646 [Th 40 Req 4775 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: leaving group svc_3056_eap (returns handled) for request 4775 2024-04-01 18:30:24,646 [Th 40 Req 4775 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - The request contains following state_items 2024-04-01 18:30:24,646 [Th 40 Req 4775 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Service-State = 0x00ee0024009300c4a71200004cdbd2a511a387c4bf4d56786a0f1343 2024-04-01 18:30:24,646 [Th 40 Req 4775 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - EAP-State = 0x00c0000f00da008fa712000032dab9cf056e0151 2024-04-01 18:30:24,646 [Th 40 Req 4775 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - The request contains following session_id 2024-04-01 18:30:24,646 [Th 40 Req 4775 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Session-Id = "R0000003b-01-660ad310" 2024-04-01 18:30:24,646 [Th 40 Req 4775 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - The request contains following session messages 2024-04-01 18:30:24,646 [Th 40 Req 4775 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - The request contains following persistent config items 2024-04-01 18:30:24,646 [Th 40 Req 4775 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - User-Password = 2024-04-01 18:30:24,646 [Th 40 Req 4775 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Persisted-User-Name = "MedoB_Training" 2024-04-01 18:30:24,646 [Th 40 Req 4775 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Authentication-Source = "Local:localhost" 2024-04-01 18:30:24,646 [Th 40 Req 4775 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Authentication-Source-Name = "Endpoints Repository]" 2024-04-01 18:30:24,646 [Th 40 Req 4775 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Authentication-Source-Id = 4 2024-04-01 18:30:24,646 [Th 40 Req 4775 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - EAP-TLS-Version = "1.2" 2024-04-01 18:30:24,646 [Th 40 Req 4775 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Policy Evaluation Status: 0, Request Status: 0, Error Code: 201 2024-04-01 18:30:24,646 [Th 40 Req 4775 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - reqst_node_alloc: pkt info ptr - 0x5c01d750, pkt info size 16 2024-04-01 18:30:24,646 [Th 40 Req 4775 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - reqst_node_alloc: updated pkt info - pkt # 5 2024-04-01 18:30:24,646 [Th 40 Req 4775 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Sending Access-Challenge of id 143 to 10.2.200.32 port 1812 2024-04-01 18:30:24,646 [Th 40 Req 4775 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - EAP-Message = 0x010704060d40774fbfa57a179967d155f5fb006fa57d07b7d77486bc7160e3b8119b8dc71ad2f5ad0eab5573016293c0de072d9b5ebd464b688b7b648e74f4b91f2a6b4dfb08e30ef1bd960a0944b3a2477368527ce4632eed593a876849ac99dafb39e3ca8229935319e563c2b9afd8bca3682d3821d19aab8a670fb444ae5895212537b9ecb053931d8a25fa1b94c3d71aba13008040757d2561f8d62d7a273630ce78fff461755f3c80a8b0c029183236a116f9549981f3fdb8d3c3dfbe0ee596d37ff32f5e7f5184df7328863addaaf8b3e1668f4f56533bfca87eb346921b515d49a285385138e6213910a393e1e2da82aa2d1ea1881f52792581 2024-04-01 18:30:24,646 [Th 40 Req 4775 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - EAP-Message = 0x7aba071d8613a7062f77f96400053e3082053a30820322a003020102021025e56a3fb36c32b84fd0b9931defa843300d06092a864886f70d01010b0500301d311b3019060355040313124d65646f6368656d696520526f6f74204341301e170d3138303431323038303832385a170d3430303532363133323333325a301d311b3019060355040313124d65646f6368656d696520526f6f7420434130820222300d06092a864886f70d01010105000382020f003082020a0282020100b8269c5c4ed5bb166945342f1d8ebfca2bdaf724ffcb82084aa72313da4cb27cae8ace659804f1bf071ad72d4150030e94dad36a9bcacf4dffbf3f2eb484809444 2024-04-01 18:30:24,646 [Th 40 Req 4775 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - EAP-Message = 0x65ac388e25eb6e0b3767fbb9859429a24e0142debe2d33151d3c6afea927e5d9a6d67fe69b2e1256d498e088283536e96b341d3caf44cf86edb48dfd1c21e1e468eea8dc2772454d510686235327584ee35741d0b7a0941a204b5fd61b167d7e6515d6fbd028de611c218f6dd5e22e387aa7cdca0440d41f878367d9e49ed89a8dd73430864431f0c622bfa491b27bd21717ca9b4ba0a8451d6cff0470feaa95cc2571c69711d487673b8f02bcfad98030903e3f663ce182ac2cf121c1a03af3de7150ff8ab071d4a524fd7dcf4d250986374bcf7ae2be8ac503b6691c7c6fc14fb3a712960ca23d8704e533cfd4a8a05acc4f8b0027674c9a9e882cb6 2024-04-01 18:30:24,646 [Th 40 Req 4775 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - EAP-Message = 0xf0ae0aa9f4dc2ae6dac0fffbe371a14c99f595a06edd55f5a2559e13de40a2c1e2d0ed50465c2e6bb2783179c80f276b68ddcc3efe429a28da7a2f2edc27713ed87c10ae533b27a6023d5d5bf2efbb229f616789cd69365daf3100ff73ef1bb8096817f118d22a51aca84861b65a6eec34f4628740bea1ed2819357f833d2d5ec2e8ec7049651e7d14e73991607715d1b762e2a1f8f7fe90ada7936be8ff49f7b32ddef67e9a8b2c68c11f86baa732885917251311e2c3eb5ae46690c0f94d60cc210203010001a3763074300b0603551d0f040403020186300f0603551d130101ff040530030101ff301d0603551d0e04160414fbc7ada7499ab3a0ef 2024-04-01 18:30:24,646 [Th 40 Req 4775 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - EAP-Message = 0x70214bb9ff60fc8bf7ab20301006092b0601 2024-04-01 18:30:24,646 [Th 40 Req 4775 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Message-Authenticator = 0x00000000000000000000000000000000 2024-04-01 18:30:24,646 [Th 40 Req 4775 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - State = 0x414263416251416e4147716e4567414163396f335a48772f4837446332687a314977345165673d3d 2024-04-01 18:30:24,646 [Th 40 Req 4775 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - reqst_update_state node pkt info ptr 0x5c01d750, req cur pkt # 5, node cur pkt # 5 2024-04-01 18:30:24,646 [Th 40 Req 4775 SessId R0000003b-01-660ad310] INFO RadiusServer.Radius - reqst_update_state: Access-Challenge 143:1120:48-4a-e9-c8-59-c4:ABcAbQAnAGqnEgAAc9o3ZHw/H7Dc2hz1Iw4Qeg== 2024-04-01 18:30:24,646 [Th 40 Req 4775 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Finished request 4775 2024-04-01 18:30:24,646 [Th 40 Req 4775 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Going to the next request 2024-04-01 18:30:24,650 [Th 43 Req 4776] DEBUG RadiusServer.Radius - Session-Id = "R0000003b-01-660ad310" 2024-04-01 18:30:24,650 [Th 43 Req 4776 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Processing the authorize section of radiusd.conf 2024-04-01 18:30:24,650 [Th 43 Req 4776 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: entering group authorize for request 4776 2024-04-01 18:30:24,650 [Th 43 Req 4776 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallauthorize]: module "dacl" returns noop for request 4776 2024-04-01 18:30:24,650 [Th 43 Req 4776 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_service: The request has Service-State attribute 2024-04-01 18:30:24,650 [Th 43 Req 4776 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_service: svcreq_list_find Service-State = 0x00ee0024009300c4a71200004cdbd2a511a387c4bf4d56786a0f1343, Session-Id = "R0000003b-01-660ad310" 2024-04-01 18:30:24,650 [Th 43 Req 4776 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_service: Request found, released from the list 2024-04-01 18:30:24,650 [Th 43 Req 4776 SessId R0000003b-01-660ad310] INFO RadiusServer.Radius - rlm_service: The request was categorized into service "{ArubaOS SW} Wired Desktop DYN VLAN 802.1X" - 144:438:48-4a-e9-c8-59-c4 2024-04-01 18:30:24,650 [Th 43 Req 4776 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_service: Checking for username before "@" 2024-04-01 18:30:24,650 [Th 43 Req 4776 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_service: No delimiter. 2024-04-01 18:30:24,650 [Th 43 Req 4776 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_service: svcreq_list_add Service-State = 0x00a500c3004400eca8120000bb79b4f96414ec3de54f073f1853063d, Session-Id = "R0000003b-01-660ad310" 2024-04-01 18:30:24,650 [Th 43 Req 4776 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallauthorize]: module "service" returns ok for request 4776 2024-04-01 18:30:24,650 [Th 43 Req 4776 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: leaving group authorize (returns ok) for request 4776 2024-04-01 18:30:24,650 [Th 43 Req 4776 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Found Autz-Type svc_{ArubaOS SW} Wired Desktop DYN VLAN 802.1X_3056 2024-04-01 18:30:24,650 [Th 43 Req 4776 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Processing the authorize section of radiusd.conf 2024-04-01 18:30:24,650 [Th 43 Req 4776 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: entering group svc_{ArubaOS SW} Wired Desktop DYN VLAN 802.1X_3056 for request 4776 2024-04-01 18:30:24,650 [Th 43 Req 4776 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: entering group for request 4776 2024-04-01 18:30:24,650 [Th 43 Req 4776 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: entering redundant-sticky group for request 4776 2024-04-01 18:30:24,650 [Th 43 Req 4776 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Redundant-sticky: Module authsrc_3001 is active 2024-04-01 18:30:24,650 [Th 43 Req 4776 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_ldap: Request contains authsrc items, returning 2024-04-01 18:30:24,650 [Th 43 Req 4776 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallauthorize]: module "authsrc_3001" returns notfound for request 4776 2024-04-01 18:30:24,650 [Th 43 Req 4776 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: redundant-sticky group returns notfound for request 4776 2024-04-01 18:30:24,650 [Th 43 Req 4776 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_sql (authsrc_4): Request contains authsrc items, returning 2024-04-01 18:30:24,650 [Th 43 Req 4776 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallauthorize]: module "authsrc_4" returns ok for request 4776 2024-04-01 18:30:24,650 [Th 43 Req 4776 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: leaving group (returns ok) for request 4776 2024-04-01 18:30:24,650 [Th 43 Req 4776 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: Deleting Proxy-To-Realm and Post-Proxy-Type attributes 2024-04-01 18:30:24,650 [Th 43 Req 4776 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: EAP packet type response id 7 length 6 2024-04-01 18:30:24,651 [Th 43 Req 4776 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: No EAP Start, assuming it's an on-going EAP conversation 2024-04-01 18:30:24,651 [Th 43 Req 4776 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallauthorize]: module "svc_3056_eap" returns updated for request 4776 2024-04-01 18:30:24,651 [Th 43 Req 4776 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_auth_check: Allowed authentication methods: svc_3056_eap 2024-04-01 18:30:24,651 [Th 43 Req 4776 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - radius: No MS Identity VP 2024-04-01 18:30:24,651 [Th 43 Req 4776 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_auth_check: allowed Authentication method svc_3056_eap set. 2024-04-01 18:30:24,651 [Th 43 Req 4776 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallauthorize]: module "svc_3056_auth_check" returns ok for request 4776 2024-04-01 18:30:24,651 [Th 43 Req 4776 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: leaving group svc_{ArubaOS SW} Wired Desktop DYN VLAN 802.1X_3056 (returns updated) for request 4776 2024-04-01 18:30:24,651 [Th 43 Req 4776 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rad_check_password: Found Auth-Type svc_3056_eap 2024-04-01 18:30:24,651 [Th 43 Req 4776 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - auth: type "svc_3056_eap" 2024-04-01 18:30:24,651 [Th 43 Req 4776 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Processing the authenticate section of radiusd.conf 2024-04-01 18:30:24,651 [Th 43 Req 4776 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: entering group svc_3056_eap for request 4776 2024-04-01 18:30:24,651 [Th 43 Req 4776 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: eaplist_find EAP-State = 0x00c0000f00da008fa712000032dab9cf056e0151 2024-04-01 18:30:24,651 [Th 43 Req 4776 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: Request found, released from the list 2024-04-01 18:30:24,651 [Th 43 Req 4776 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: EAP/tls 2024-04-01 18:30:24,651 [Th 43 Req 4776 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: processing type tls instance EAP TLS] 2024-04-01 18:30:24,651 [Th 43 Req 4776 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap_tls: Authenticate 2024-04-01 18:30:24,651 [Th 43 Req 4776 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap_tls: Request has authentication source Local:localhost 2024-04-01 18:30:24,651 [Th 43 Req 4776 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap_tls: processing TLS 2024-04-01 18:30:24,651 [Th 43 Req 4776 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap_tls: Received EAP-TLS ACK message 2024-04-01 18:30:24,651 [Th 43 Req 4776 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap_tls: ack handshake fragment handler 2024-04-01 18:30:24,651 [Th 43 Req 4776 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - eaptls_verify returned 1 2024-04-01 18:30:24,651 [Th 43 Req 4776 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - eaptls_process returned 13 2024-04-01 18:30:24,651 [Th 43 Req 4776 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: eap_compose returned 3 2024-04-01 18:30:24,651 [Th 43 Req 4776 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: eap_list_add EAP-State = 0x009900a300cf002ba81200006bf34db6859f972b 2024-04-01 18:30:24,651 [Th 43 Req 4776 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallauthenticate]: module "svc_3056_eap" returns handled for request 4776 2024-04-01 18:30:24,651 [Th 43 Req 4776 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: leaving group svc_3056_eap (returns handled) for request 4776 2024-04-01 18:30:24,651 [Th 43 Req 4776 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - The request contains following state_items 2024-04-01 18:30:24,651 [Th 43 Req 4776 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Service-State = 0x00a500c3004400eca8120000bb79b4f96414ec3de54f073f1853063d 2024-04-01 18:30:24,651 [Th 43 Req 4776 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - EAP-State = 0x009900a300cf002ba81200006bf34db6859f972b 2024-04-01 18:30:24,651 [Th 43 Req 4776 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - The request contains following session_id 2024-04-01 18:30:24,651 [Th 43 Req 4776 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Session-Id = "R0000003b-01-660ad310" 2024-04-01 18:30:24,651 [Th 43 Req 4776 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - The request contains following session messages 2024-04-01 18:30:24,651 [Th 43 Req 4776 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - The request contains following persistent config items 2024-04-01 18:30:24,651 [Th 43 Req 4776 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - User-Password = 2024-04-01 18:30:24,651 [Th 43 Req 4776 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Persisted-User-Name = "MedoB_Training" 2024-04-01 18:30:24,651 [Th 43 Req 4776 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Authentication-Source = "Local:localhost" 2024-04-01 18:30:24,652 [Th 43 Req 4776 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Authentication-Source-Name = "Endpoints Repository]" 2024-04-01 18:30:24,652 [Th 43 Req 4776 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Authentication-Source-Id = 4 2024-04-01 18:30:24,652 [Th 43 Req 4776 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - EAP-TLS-Version = "1.2" 2024-04-01 18:30:24,652 [Th 43 Req 4776 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Policy Evaluation Status: 0, Request Status: 0, Error Code: 201 2024-04-01 18:30:24,652 [Th 43 Req 4776 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - reqst_node_alloc: pkt info ptr - 0x5c01d750, pkt info size 16 2024-04-01 18:30:24,652 [Th 43 Req 4776 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - reqst_node_alloc: updated pkt info - pkt # 6 2024-04-01 18:30:24,652 [Th 43 Req 4776 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Sending Access-Challenge of id 144 to 10.2.200.32 port 1812 2024-04-01 18:30:24,652 [Th 43 Req 4776 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - EAP-Message = 0x010804060d400401823715010403020101302306092b0601040182371502041604148332bfedffd54e181462bbf659203c4b616c2168300d06092a864886f70d01010b0500038202010075493e115efc2465c9b9bfec8356036023f17fe3953abce3db0e411844562648bb6baab9ce22dd7e15d647f0edd476728eb0c69dec6181295ed55373d35c5610e7b3612600224222610baedebfbe2c1fced8b275e456ff8921b4ecb6b6a35973a69e40d40418db6426c20ba9b856cd2a35ac11398ff455d638241bf942559a9430bce0a5c6110728cbfd5da1bff3118c3e1862a949265cba6fc6cd03e388984434010394e52adb978c3d71535e1ad064a1d3ea 2024-04-01 18:30:24,652 [Th 43 Req 4776 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - EAP-Message = 0xe77ca8c82bb60ba53d08070eef04551606d07a3131e127a062d0ca954c22260c7908e7580461c06eb0d09db3020fe3242d2f639dd00ec878bfde469c99dc1fee8c7ad67fe0053143e677c5bcb28708d4cce5eb0ec3070803622b489e6caabf8c6ebd76f7b163ee8a499b29930908214ba17a38896d0535399edafbcafdc88de7e2a399eda444d6966776804581b9305571142dac067d5501c965682f21fc5b0e10d4e4a3b5ffaaa12b848d6d7d745bcd918918842acdb7bdeac552c2d6075d9ffc2f98fbccd6cf002d997e235b898e4c880cbf4e786b0076beea36afb13451ff2adf0556c6f009501a3c454b8b8dd7cfb4a362c1a29d0afe079297af76 2024-04-01 18:30:24,652 [Th 43 Req 4776 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - EAP-Message = 0xd4be8215266531026b6fdb943df1981f2736f95f67fe4440e80f70dfbdd94f88e901166d61361f0f97522943da79630014c67e4a74932b02aca11e64c8560136192d8d8ef189996763ba1679a7e0b6131603030c8e0d000c8a03010240002e0403050306030807080808090804080a0805080b08060401050106010303030104020502060203020203020102020c54008b30818831143012060355040b130b446576696365547275737431133011060355040b130a4f7065726174696f6e7331173015060355040a130e4172756261204e6574776f726b73310b3009060355040613025553313530330603550403132c4172756261204e6574776f726b 2024-04-01 18:30:24,652 [Th 43 Req 4776 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - EAP-Message = 0x73205472757374656420436f6d707574696e6720526f6f7420434120312e3000633061310b300906035504061302555331153013060355040a130c446967694365727420496e6331193017060355040b13107777772e64696769636572742e636f6d3120301e06035504031317446967694365727420476c6f62616c20526f6f74204732008b308188310b3009060355040613025553311330110603550408130a4e6577204a6572736579311430120603550407130b4a65727365792043697479311e301c060355040a131554686520555345525452555354204e6574776f726b312e302c060355040313255553455254727573742052534120436572 2024-04-01 18:30:24,652 [Th 43 Req 4776 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - EAP-Message = 0x74696669636174696f6e20417574686f7269 2024-04-01 18:30:24,652 [Th 43 Req 4776 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Message-Authenticator = 0x00000000000000000000000000000000 2024-04-01 18:30:24,652 [Th 43 Req 4776 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - State = 0x414f774175774143414d6d6f4567414138305230705536337a6468475a626945586b2b5071513d3d 2024-04-01 18:30:24,652 [Th 43 Req 4776 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - reqst_update_state node pkt info ptr 0x5c01d750, req cur pkt # 6, node cur pkt # 6 2024-04-01 18:30:24,652 [Th 43 Req 4776 SessId R0000003b-01-660ad310] INFO RadiusServer.Radius - reqst_update_state: Access-Challenge 144:1120:48-4a-e9-c8-59-c4:AOwAuwACAMmoEgAA80R0pU63zdhGZbiEXk+PqQ== 2024-04-01 18:30:24,652 [Th 43 Req 4776 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Finished request 4776 2024-04-01 18:30:24,652 [Th 43 Req 4776 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Going to the next request 2024-04-01 18:30:24,656 [Th 36 Req 4777] DEBUG RadiusServer.Radius - Session-Id = "R0000003b-01-660ad310" 2024-04-01 18:30:24,656 [Th 36 Req 4777 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Processing the authorize section of radiusd.conf 2024-04-01 18:30:24,656 [Th 36 Req 4777 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: entering group authorize for request 4777 2024-04-01 18:30:24,656 [Th 36 Req 4777 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallauthorize]: module "dacl" returns noop for request 4777 2024-04-01 18:30:24,656 [Th 36 Req 4777 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_service: The request has Service-State attribute 2024-04-01 18:30:24,656 [Th 36 Req 4777 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_service: svcreq_list_find Service-State = 0x00a500c3004400eca8120000bb79b4f96414ec3de54f073f1853063d, Session-Id = "R0000003b-01-660ad310" 2024-04-01 18:30:24,656 [Th 36 Req 4777 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_service: Request found, released from the list 2024-04-01 18:30:24,656 [Th 36 Req 4777 SessId R0000003b-01-660ad310] INFO RadiusServer.Radius - rlm_service: The request was categorized into service "{ArubaOS SW} Wired Desktop DYN VLAN 802.1X" - 145:438:48-4a-e9-c8-59-c4 2024-04-01 18:30:24,656 [Th 36 Req 4777 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_service: Checking for username before "@" 2024-04-01 18:30:24,656 [Th 36 Req 4777 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_service: No delimiter. 2024-04-01 18:30:24,656 [Th 36 Req 4777 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_service: svcreq_list_add Service-State = 0x0076008e003b002ea912000075134260f6629a85a84c035b622a2115, Session-Id = "R0000003b-01-660ad310" 2024-04-01 18:30:24,656 [Th 36 Req 4777 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallauthorize]: module "service" returns ok for request 4777 2024-04-01 18:30:24,656 [Th 36 Req 4777 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: leaving group authorize (returns ok) for request 4777 2024-04-01 18:30:24,656 [Th 36 Req 4777 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Found Autz-Type svc_{ArubaOS SW} Wired Desktop DYN VLAN 802.1X_3056 2024-04-01 18:30:24,656 [Th 36 Req 4777 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Processing the authorize section of radiusd.conf 2024-04-01 18:30:24,656 [Th 36 Req 4777 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: entering group svc_{ArubaOS SW} Wired Desktop DYN VLAN 802.1X_3056 for request 4777 2024-04-01 18:30:24,656 [Th 36 Req 4777 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: entering group for request 4777 2024-04-01 18:30:24,656 [Th 36 Req 4777 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: entering redundant-sticky group for request 4777 2024-04-01 18:30:24,657 [Th 36 Req 4777 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Redundant-sticky: Module authsrc_3001 is active 2024-04-01 18:30:24,657 [Th 36 Req 4777 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_ldap: Request contains authsrc items, returning 2024-04-01 18:30:24,657 [Th 36 Req 4777 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallauthorize]: module "authsrc_3001" returns notfound for request 4777 2024-04-01 18:30:24,657 [Th 36 Req 4777 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: redundant-sticky group returns notfound for request 4777 2024-04-01 18:30:24,657 [Th 36 Req 4777 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_sql (authsrc_4): Request contains authsrc items, returning 2024-04-01 18:30:24,657 [Th 36 Req 4777 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallauthorize]: module "authsrc_4" returns ok for request 4777 2024-04-01 18:30:24,657 [Th 36 Req 4777 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: leaving group (returns ok) for request 4777 2024-04-01 18:30:24,657 [Th 36 Req 4777 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: Deleting Proxy-To-Realm and Post-Proxy-Type attributes 2024-04-01 18:30:24,657 [Th 36 Req 4777 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: EAP packet type response id 8 length 6 2024-04-01 18:30:24,657 [Th 36 Req 4777 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: No EAP Start, assuming it's an on-going EAP conversation 2024-04-01 18:30:24,657 [Th 36 Req 4777 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallauthorize]: module "svc_3056_eap" returns updated for request 4777 2024-04-01 18:30:24,657 [Th 36 Req 4777 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_auth_check: Allowed authentication methods: svc_3056_eap 2024-04-01 18:30:24,657 [Th 36 Req 4777 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - radius: No MS Identity VP 2024-04-01 18:30:24,657 [Th 36 Req 4777 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_auth_check: allowed Authentication method svc_3056_eap set. 2024-04-01 18:30:24,657 [Th 36 Req 4777 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallauthorize]: module "svc_3056_auth_check" returns ok for request 4777 2024-04-01 18:30:24,657 [Th 36 Req 4777 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: leaving group svc_{ArubaOS SW} Wired Desktop DYN VLAN 802.1X_3056 (returns updated) for request 4777 2024-04-01 18:30:24,657 [Th 36 Req 4777 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rad_check_password: Found Auth-Type svc_3056_eap 2024-04-01 18:30:24,657 [Th 36 Req 4777 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - auth: type "svc_3056_eap" 2024-04-01 18:30:24,657 [Th 36 Req 4777 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Processing the authenticate section of radiusd.conf 2024-04-01 18:30:24,657 [Th 36 Req 4777 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: entering group svc_3056_eap for request 4777 2024-04-01 18:30:24,657 [Th 36 Req 4777 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: eaplist_find EAP-State = 0x009900a300cf002ba81200006bf34db6859f972b 2024-04-01 18:30:24,657 [Th 36 Req 4777 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: Request found, released from the list 2024-04-01 18:30:24,657 [Th 36 Req 4777 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: EAP/tls 2024-04-01 18:30:24,657 [Th 36 Req 4777 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: processing type tls instance EAP TLS] 2024-04-01 18:30:24,657 [Th 36 Req 4777 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap_tls: Authenticate 2024-04-01 18:30:24,657 [Th 36 Req 4777 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap_tls: Request has authentication source Local:localhost 2024-04-01 18:30:24,657 [Th 36 Req 4777 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap_tls: processing TLS 2024-04-01 18:30:24,657 [Th 36 Req 4777 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap_tls: Received EAP-TLS ACK message 2024-04-01 18:30:24,657 [Th 36 Req 4777 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap_tls: ack handshake fragment handler 2024-04-01 18:30:24,657 [Th 36 Req 4777 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - eaptls_verify returned 1 2024-04-01 18:30:24,657 [Th 36 Req 4777 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - eaptls_process returned 13 2024-04-01 18:30:24,657 [Th 36 Req 4777 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: eap_compose returned 3 2024-04-01 18:30:24,657 [Th 36 Req 4777 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: eap_list_add EAP-State = 0x00c7005900ff009aa9120000d348bc62603ea929 2024-04-01 18:30:24,657 [Th 36 Req 4777 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallauthenticate]: module "svc_3056_eap" returns handled for request 4777 2024-04-01 18:30:24,657 [Th 36 Req 4777 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: leaving group svc_3056_eap (returns handled) for request 4777 2024-04-01 18:30:24,657 [Th 36 Req 4777 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - The request contains following state_items 2024-04-01 18:30:24,657 [Th 36 Req 4777 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Service-State = 0x0076008e003b002ea912000075134260f6629a85a84c035b622a2115 2024-04-01 18:30:24,657 [Th 36 Req 4777 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - EAP-State = 0x00c7005900ff009aa9120000d348bc62603ea929 2024-04-01 18:30:24,657 [Th 36 Req 4777 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - The request contains following session_id 2024-04-01 18:30:24,657 [Th 36 Req 4777 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Session-Id = "R0000003b-01-660ad310" 2024-04-01 18:30:24,657 [Th 36 Req 4777 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - The request contains following session messages 2024-04-01 18:30:24,657 [Th 36 Req 4777 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - The request contains following persistent config items 2024-04-01 18:30:24,658 [Th 36 Req 4777 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - User-Password = 2024-04-01 18:30:24,658 [Th 36 Req 4777 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Persisted-User-Name = "MedoB_Training" 2024-04-01 18:30:24,658 [Th 36 Req 4777 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Authentication-Source = "Local:localhost" 2024-04-01 18:30:24,658 [Th 36 Req 4777 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Authentication-Source-Name = "Endpoints Repository]" 2024-04-01 18:30:24,658 [Th 36 Req 4777 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Authentication-Source-Id = 4 2024-04-01 18:30:24,658 [Th 36 Req 4777 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - EAP-TLS-Version = "1.2" 2024-04-01 18:30:24,658 [Th 36 Req 4777 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Policy Evaluation Status: 0, Request Status: 0, Error Code: 201 2024-04-01 18:30:24,658 [Th 36 Req 4777 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - reqst_node_alloc: pkt info ptr - 0x5c01d750, pkt info size 16 2024-04-01 18:30:24,658 [Th 36 Req 4777 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - reqst_node_alloc: updated pkt info - pkt # 7 2024-04-01 18:30:24,658 [Th 36 Req 4777 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Sending Access-Challenge of id 145 to 10.2.200.32 port 1812 2024-04-01 18:30:24,658 [Th 36 Req 4777 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - EAP-Message = 0x010904060d407479008b30818831133011060a0992268993f22c6401191603636f6d311d301b060a0992268993f22c640119160d61727562616e6574776f726b73311a3018060a0992268993f22c640119160a6465766963657369676e313630340603550403132d4172756261204e6574776f726b73205472757374656420436f6d707574696e672049737375696e672043412032008d30818a310b300906035504061302555331173015060355040a130e4172756261204e6574776f726b7331143012060355040b130b446576696365547275737431133011060355040b130a4f7065726174696f6e73313730350603550403132e4172756261204e 2024-04-01 18:30:24,658 [Th 36 Req 4777 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - EAP-Message = 0x6574776f726b73205472757374656420436f6d707574696e6720506f6c69637920434120322e3000d53081d2310b30090603550406130255533113301106035504080c0a43616c69666f726e69613112301006035504070c0953756e6e7976616c6531173015060355040a0c0e4172756261204e6574776f726b733140303e06035504030c37436c65617250617373204f6e626f617264204c6f63616c20436572746966696361746520417574686f7269747920285369676e696e6729313f303d06092a864886f70d010901163038643661336164372d333334362d343162642d396165622d356161323666376163633263406578616d706c652e636f 2024-04-01 18:30:24,658 [Th 36 Req 4777 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - EAP-Message = 0x6d00cb3081c8310b30090603550406130255533113301106035504080c0a43616c69666f726e69613112301006035504070c0953756e6e7976616c6531173015060355040a0c0e4172756261204e6574776f726b733136303406035504030c2d436c65617250617373204f6e626f617264204c6f63616c20436572746966696361746520417574686f72697479313f303d06092a864886f70d010901163038643661336164372d333334362d343162642d396165622d356161323666376163633263406578616d706c652e636f6d001f301d311b3019060355040313124d65646f6368656d696520526f6f742043410057305531153013060a09922689 2024-04-01 18:30:24,658 [Th 36 Req 4777 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - EAP-Message = 0x93f22c64011916056c6f63616c311a3018060a0992268993f22c640119160a4d45444f4348454d49453120301e060355040313174d65646f6368656d69652049737375696e67204341203100ca3081c7310b3009060355040613024359310b300906035504080c0243593111300f06035504070c084c696d6173736f6c31173015060355040a0c0e4d65646f6368656d6965204c5444310b3009060355040b0c0249543145304306035504030c3c4d65646f20436c65617250617373204f6e626f617264204c6f63616c20436572746966696361746520417574686f7269747920285369676e696e6729312b302906092a864886f70d010901161c6379 2024-04-01 18:30:24,658 [Th 36 Req 4777 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - EAP-Message = 0x6265727365637572697479406d65646f6368 2024-04-01 18:30:24,658 [Th 36 Req 4777 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Message-Authenticator = 0x00000000000000000000000000000000 2024-04-01 18:30:24,658 [Th 36 Req 4777 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - State = 0x414138417a77436441414370456741416e384a365a6f6550766f504a636e766e4372486553513d3d 2024-04-01 18:30:24,658 [Th 36 Req 4777 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - reqst_update_state node pkt info ptr 0x5c01d750, req cur pkt # 7, node cur pkt # 7 2024-04-01 18:30:24,658 [Th 36 Req 4777 SessId R0000003b-01-660ad310] INFO RadiusServer.Radius - reqst_update_state: Access-Challenge 145:1120:48-4a-e9-c8-59-c4:AA8AzwCdAACpEgAAn8J6ZoePvoPJcnvnCrHeSQ== 2024-04-01 18:30:24,658 [Th 36 Req 4777 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Finished request 4777 2024-04-01 18:30:24,658 [Th 36 Req 4777 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Going to the next request 2024-04-01 18:30:24,661 [Th 41 Req 4778] DEBUG RadiusServer.Radius - Session-Id = "R0000003b-01-660ad310" 2024-04-01 18:30:24,661 [Th 41 Req 4778 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Processing the authorize section of radiusd.conf 2024-04-01 18:30:24,661 [Th 41 Req 4778 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: entering group authorize for request 4778 2024-04-01 18:30:24,661 [Th 41 Req 4778 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallauthorize]: module "dacl" returns noop for request 4778 2024-04-01 18:30:24,661 [Th 41 Req 4778 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_service: The request has Service-State attribute 2024-04-01 18:30:24,661 [Th 41 Req 4778 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_service: svcreq_list_find Service-State = 0x0076008e003b002ea912000075134260f6629a85a84c035b622a2115, Session-Id = "R0000003b-01-660ad310" 2024-04-01 18:30:24,661 [Th 41 Req 4778 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_service: Request found, released from the list 2024-04-01 18:30:24,661 [Th 41 Req 4778 SessId R0000003b-01-660ad310] INFO RadiusServer.Radius - rlm_service: The request was categorized into service "{ArubaOS SW} Wired Desktop DYN VLAN 802.1X" - 146:438:48-4a-e9-c8-59-c4 2024-04-01 18:30:24,662 [Th 41 Req 4778 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_service: Checking for username before "@" 2024-04-01 18:30:24,662 [Th 41 Req 4778 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_service: No delimiter. 2024-04-01 18:30:24,662 [Th 41 Req 4778 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_service: svcreq_list_add Service-State = 0x00de00f800e40056aa120000877e89abf9d449a28eca93f71aae9887, Session-Id = "R0000003b-01-660ad310" 2024-04-01 18:30:24,662 [Th 41 Req 4778 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallauthorize]: module "service" returns ok for request 4778 2024-04-01 18:30:24,662 [Th 41 Req 4778 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: leaving group authorize (returns ok) for request 4778 2024-04-01 18:30:24,662 [Th 41 Req 4778 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Found Autz-Type svc_{ArubaOS SW} Wired Desktop DYN VLAN 802.1X_3056 2024-04-01 18:30:24,662 [Th 41 Req 4778 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Processing the authorize section of radiusd.conf 2024-04-01 18:30:24,662 [Th 41 Req 4778 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: entering group svc_{ArubaOS SW} Wired Desktop DYN VLAN 802.1X_3056 for request 4778 2024-04-01 18:30:24,662 [Th 41 Req 4778 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: entering group for request 4778 2024-04-01 18:30:24,662 [Th 41 Req 4778 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: entering redundant-sticky group for request 4778 2024-04-01 18:30:24,662 [Th 41 Req 4778 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Redundant-sticky: Module authsrc_3001 is active 2024-04-01 18:30:24,662 [Th 41 Req 4778 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_ldap: Request contains authsrc items, returning 2024-04-01 18:30:24,662 [Th 41 Req 4778 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallauthorize]: module "authsrc_3001" returns notfound for request 4778 2024-04-01 18:30:24,662 [Th 41 Req 4778 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: redundant-sticky group returns notfound for request 4778 2024-04-01 18:30:24,662 [Th 41 Req 4778 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_sql (authsrc_4): Request contains authsrc items, returning 2024-04-01 18:30:24,662 [Th 41 Req 4778 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallauthorize]: module "authsrc_4" returns ok for request 4778 2024-04-01 18:30:24,662 [Th 41 Req 4778 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: leaving group (returns ok) for request 4778 2024-04-01 18:30:24,662 [Th 41 Req 4778 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: Deleting Proxy-To-Realm and Post-Proxy-Type attributes 2024-04-01 18:30:24,662 [Th 41 Req 4778 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: EAP packet type response id 9 length 6 2024-04-01 18:30:24,662 [Th 41 Req 4778 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: No EAP Start, assuming it's an on-going EAP conversation 2024-04-01 18:30:24,662 [Th 41 Req 4778 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallauthorize]: module "svc_3056_eap" returns updated for request 4778 2024-04-01 18:30:24,662 [Th 41 Req 4778 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_auth_check: Allowed authentication methods: svc_3056_eap 2024-04-01 18:30:24,662 [Th 41 Req 4778 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - radius: No MS Identity VP 2024-04-01 18:30:24,662 [Th 41 Req 4778 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_auth_check: allowed Authentication method svc_3056_eap set. 2024-04-01 18:30:24,662 [Th 41 Req 4778 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallauthorize]: module "svc_3056_auth_check" returns ok for request 4778 2024-04-01 18:30:24,662 [Th 41 Req 4778 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: leaving group svc_{ArubaOS SW} Wired Desktop DYN VLAN 802.1X_3056 (returns updated) for request 4778 2024-04-01 18:30:24,662 [Th 41 Req 4778 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rad_check_password: Found Auth-Type svc_3056_eap 2024-04-01 18:30:24,662 [Th 41 Req 4778 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - auth: type "svc_3056_eap" 2024-04-01 18:30:24,662 [Th 41 Req 4778 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Processing the authenticate section of radiusd.conf 2024-04-01 18:30:24,662 [Th 41 Req 4778 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: entering group svc_3056_eap for request 4778 2024-04-01 18:30:24,662 [Th 41 Req 4778 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: eaplist_find EAP-State = 0x00c7005900ff009aa9120000d348bc62603ea929 2024-04-01 18:30:24,662 [Th 41 Req 4778 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: Request found, released from the list 2024-04-01 18:30:24,662 [Th 41 Req 4778 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: EAP/tls 2024-04-01 18:30:24,662 [Th 41 Req 4778 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: processing type tls instance EAP TLS] 2024-04-01 18:30:24,662 [Th 41 Req 4778 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap_tls: Authenticate 2024-04-01 18:30:24,662 [Th 41 Req 4778 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap_tls: Request has authentication source Local:localhost 2024-04-01 18:30:24,662 [Th 41 Req 4778 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap_tls: processing TLS 2024-04-01 18:30:24,662 [Th 41 Req 4778 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap_tls: Received EAP-TLS ACK message 2024-04-01 18:30:24,662 [Th 41 Req 4778 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap_tls: ack handshake fragment handler 2024-04-01 18:30:24,662 [Th 41 Req 4778 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - eaptls_verify returned 1 2024-04-01 18:30:24,662 [Th 41 Req 4778 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - eaptls_process returned 13 2024-04-01 18:30:24,662 [Th 41 Req 4778 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: eap_compose returned 3 2024-04-01 18:30:24,662 [Th 41 Req 4778 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: eap_list_add EAP-State = 0x00a100e700e900bbaa1200009d4f33957921f84c 2024-04-01 18:30:24,662 [Th 41 Req 4778 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallauthenticate]: module "svc_3056_eap" returns handled for request 4778 2024-04-01 18:30:24,662 [Th 41 Req 4778 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: leaving group svc_3056_eap (returns handled) for request 4778 2024-04-01 18:30:24,662 [Th 41 Req 4778 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - The request contains following state_items 2024-04-01 18:30:24,662 [Th 41 Req 4778 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Service-State = 0x00de00f800e40056aa120000877e89abf9d449a28eca93f71aae9887 2024-04-01 18:30:24,662 [Th 41 Req 4778 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - EAP-State = 0x00a100e700e900bbaa1200009d4f33957921f84c 2024-04-01 18:30:24,662 [Th 41 Req 4778 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - The request contains following session_id 2024-04-01 18:30:24,662 [Th 41 Req 4778 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Session-Id = "R0000003b-01-660ad310" 2024-04-01 18:30:24,662 [Th 41 Req 4778 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - The request contains following session messages 2024-04-01 18:30:24,662 [Th 41 Req 4778 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - The request contains following persistent config items 2024-04-01 18:30:24,662 [Th 41 Req 4778 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - User-Password = 2024-04-01 18:30:24,662 [Th 41 Req 4778 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Persisted-User-Name = "MedoB_Training" 2024-04-01 18:30:24,662 [Th 41 Req 4778 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Authentication-Source = "Local:localhost" 2024-04-01 18:30:24,662 [Th 41 Req 4778 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Authentication-Source-Name = "Endpoints Repository]" 2024-04-01 18:30:24,662 [Th 41 Req 4778 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Authentication-Source-Id = 4 2024-04-01 18:30:24,662 [Th 41 Req 4778 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - EAP-TLS-Version = "1.2" 2024-04-01 18:30:24,662 [Th 41 Req 4778 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Policy Evaluation Status: 0, Request Status: 0, Error Code: 201 2024-04-01 18:30:24,662 [Th 41 Req 4778 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - reqst_node_alloc: pkt info ptr - 0x5c01d750, pkt info size 16 2024-04-01 18:30:24,662 [Th 41 Req 4778 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - reqst_node_alloc: updated pkt info - pkt # 8 2024-04-01 18:30:24,662 [Th 41 Req 4778 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Sending Access-Challenge of id 146 to 10.2.200.32 port 1812 2024-04-01 18:30:24,662 [Th 41 Req 4778 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - EAP-Message = 0x010a04060d40656d69652e636f6d00c03081bd310b3009060355040613024359310b300906035504080c0243593111300f06035504070c084c696d6173736f6c31173015060355040a0c0e4d65646f6368656d6965204c5444310b3009060355040b0c024954313b303906035504030c324d65646f20436c65617250617373204f6e626f617264204c6f63616c20436572746966696361746520417574686f72697479312b302906092a864886f70d010901161c63796265727365637572697479406d65646f6368656d69652e636f6d00ab3081a8310b3009060355040613024359310b300906035504080c0243593110300e06035504070c074c656d 2024-04-01 18:30:24,662 [Th 41 Req 4778 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - EAP-Message = 0x65736f7331173015060355040a0c0e4d65646f6368656d6965204c5444310b3009060355040b0c024954312c302a06035504030c234d65646f20436c65617250617373204f6e626f61726420434120285369676e696e67293126302406092a864886f70d01090116176e657461646d696e406d65646f6368656d69652e636f6d00a130819e310b3009060355040613024359310b300906035504080c0243593110300e06035504070c074c656d65736f7331173015060355040a0c0e4d65646f6368656d6965204c5444310b3009060355040b0c0249543122302006035504030c194d65646f20436c65617250617373204f6e626f6172642043413126 2024-04-01 18:30:24,662 [Th 41 Req 4778 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - EAP-Message = 0x302406092a864886f70d01090116176e657461646d696e406d65646f6368656d69652e636f6d008b308188310b3009060355040613025553311330110603550408130a4e6577204a6572736579311430120603550407130b4a65727365792043697479311e301c060355040a131554686520555345525452555354204e6574776f726b312e302c06035504031325555345525472757374204543432043657274696669636174696f6e20417574686f72697479009230818f310b3009060355040613024742311b30190603550408131247726561746572204d616e636865737465723110300e0603550407130753616c666f726431183016060355040a 2024-04-01 18:30:24,662 [Th 41 Req 4778 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - EAP-Message = 0x130f5365637469676f204c696d69746564313730350603550403132e5365637469676f2045434320446f6d61696e2056616c69646174696f6e205365637572652053657276657220434100233021311f301d0603550403131663796463312e4d45444f4348454d49452e6c6f63616c00763074310b3009060355040613024359310b30090603550408130243593111300f060355040713084c696d6173736f6c31173015060355040a130e4d65646f6368656d6965204c5444310b3009060355040b13024954311f301d0603550403131663796463322e6d65646f6368656d69652e6c6f63616c00c13081be310b300906035504061302555331163014 2024-04-01 18:30:24,662 [Th 41 Req 4778 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - EAP-Message = 0x060355040a130d456e74727573742c20496e 2024-04-01 18:30:24,662 [Th 41 Req 4778 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Message-Authenticator = 0x00000000000000000000000000000000 2024-04-01 18:30:24,662 [Th 41 Req 4778 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - State = 0x414d554133774433414d7971456741412f37396d6d4a5531725562356a4d5751434668734f673d3d 2024-04-01 18:30:24,662 [Th 41 Req 4778 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - reqst_update_state node pkt info ptr 0x5c01d750, req cur pkt # 8, node cur pkt # 8 2024-04-01 18:30:24,662 [Th 41 Req 4778 SessId R0000003b-01-660ad310] INFO RadiusServer.Radius - reqst_update_state: Access-Challenge 146:1120:48-4a-e9-c8-59-c4:AMUA3wD3AMyqEgAA/79mmJU1rUb5jMWQCFhsOg== 2024-04-01 18:30:24,662 [Th 41 Req 4778 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Finished request 4778 2024-04-01 18:30:24,662 [Th 41 Req 4778 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Going to the next request 2024-04-01 18:30:24,665 [Th 35 Req 4779] DEBUG RadiusServer.Radius - Session-Id = "R0000003b-01-660ad310" 2024-04-01 18:30:24,665 [Th 35 Req 4779 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Processing the authorize section of radiusd.conf 2024-04-01 18:30:24,665 [Th 35 Req 4779 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: entering group authorize for request 4779 2024-04-01 18:30:24,665 [Th 35 Req 4779 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallauthorize]: module "dacl" returns noop for request 4779 2024-04-01 18:30:24,665 [Th 35 Req 4779 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_service: The request has Service-State attribute 2024-04-01 18:30:24,665 [Th 35 Req 4779 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_service: svcreq_list_find Service-State = 0x00de00f800e40056aa120000877e89abf9d449a28eca93f71aae9887, Session-Id = "R0000003b-01-660ad310" 2024-04-01 18:30:24,665 [Th 35 Req 4779 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_service: Request found, released from the list 2024-04-01 18:30:24,665 [Th 35 Req 4779 SessId R0000003b-01-660ad310] INFO RadiusServer.Radius - rlm_service: The request was categorized into service "{ArubaOS SW} Wired Desktop DYN VLAN 802.1X" - 147:438:48-4a-e9-c8-59-c4 2024-04-01 18:30:24,665 [Th 35 Req 4779 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_service: Checking for username before "@" 2024-04-01 18:30:24,665 [Th 35 Req 4779 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_service: No delimiter. 2024-04-01 18:30:24,665 [Th 35 Req 4779 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_service: svcreq_list_add Service-State = 0x00a8003900810070ab1200002f5fa466dc3babdd026dbe4f3e08dfa2, Session-Id = "R0000003b-01-660ad310" 2024-04-01 18:30:24,665 [Th 35 Req 4779 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallauthorize]: module "service" returns ok for request 4779 2024-04-01 18:30:24,665 [Th 35 Req 4779 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: leaving group authorize (returns ok) for request 4779 2024-04-01 18:30:24,665 [Th 35 Req 4779 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Found Autz-Type svc_{ArubaOS SW} Wired Desktop DYN VLAN 802.1X_3056 2024-04-01 18:30:24,665 [Th 35 Req 4779 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Processing the authorize section of radiusd.conf 2024-04-01 18:30:24,665 [Th 35 Req 4779 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: entering group svc_{ArubaOS SW} Wired Desktop DYN VLAN 802.1X_3056 for request 4779 2024-04-01 18:30:24,665 [Th 35 Req 4779 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: entering group for request 4779 2024-04-01 18:30:24,665 [Th 35 Req 4779 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: entering redundant-sticky group for request 4779 2024-04-01 18:30:24,665 [Th 35 Req 4779 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Redundant-sticky: Module authsrc_3001 is active 2024-04-01 18:30:24,665 [Th 35 Req 4779 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_ldap: Request contains authsrc items, returning 2024-04-01 18:30:24,665 [Th 35 Req 4779 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallauthorize]: module "authsrc_3001" returns notfound for request 4779 2024-04-01 18:30:24,665 [Th 35 Req 4779 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: redundant-sticky group returns notfound for request 4779 2024-04-01 18:30:24,665 [Th 35 Req 4779 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_sql (authsrc_4): Request contains authsrc items, returning 2024-04-01 18:30:24,665 [Th 35 Req 4779 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallauthorize]: module "authsrc_4" returns ok for request 4779 2024-04-01 18:30:24,665 [Th 35 Req 4779 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: leaving group (returns ok) for request 4779 2024-04-01 18:30:24,665 [Th 35 Req 4779 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: Deleting Proxy-To-Realm and Post-Proxy-Type attributes 2024-04-01 18:30:24,665 [Th 35 Req 4779 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: EAP packet type response id 10 length 6 2024-04-01 18:30:24,665 [Th 35 Req 4779 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: No EAP Start, assuming it's an on-going EAP conversation 2024-04-01 18:30:24,665 [Th 35 Req 4779 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallauthorize]: module "svc_3056_eap" returns updated for request 4779 2024-04-01 18:30:24,665 [Th 35 Req 4779 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_auth_check: Allowed authentication methods: svc_3056_eap 2024-04-01 18:30:24,665 [Th 35 Req 4779 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - radius: No MS Identity VP 2024-04-01 18:30:24,665 [Th 35 Req 4779 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_auth_check: allowed Authentication method svc_3056_eap set. 2024-04-01 18:30:24,665 [Th 35 Req 4779 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallauthorize]: module "svc_3056_auth_check" returns ok for request 4779 2024-04-01 18:30:24,665 [Th 35 Req 4779 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: leaving group svc_{ArubaOS SW} Wired Desktop DYN VLAN 802.1X_3056 (returns updated) for request 4779 2024-04-01 18:30:24,666 [Th 35 Req 4779 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rad_check_password: Found Auth-Type svc_3056_eap 2024-04-01 18:30:24,666 [Th 35 Req 4779 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - auth: type "svc_3056_eap" 2024-04-01 18:30:24,666 [Th 35 Req 4779 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Processing the authenticate section of radiusd.conf 2024-04-01 18:30:24,666 [Th 35 Req 4779 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: entering group svc_3056_eap for request 4779 2024-04-01 18:30:24,666 [Th 35 Req 4779 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: eaplist_find EAP-State = 0x00a100e700e900bbaa1200009d4f33957921f84c 2024-04-01 18:30:24,666 [Th 35 Req 4779 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: Request found, released from the list 2024-04-01 18:30:24,666 [Th 35 Req 4779 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: EAP/tls 2024-04-01 18:30:24,666 [Th 35 Req 4779 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: processing type tls instance EAP TLS] 2024-04-01 18:30:24,666 [Th 35 Req 4779 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap_tls: Authenticate 2024-04-01 18:30:24,666 [Th 35 Req 4779 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap_tls: Request has authentication source Local:localhost 2024-04-01 18:30:24,666 [Th 35 Req 4779 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap_tls: processing TLS 2024-04-01 18:30:24,666 [Th 35 Req 4779 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap_tls: Received EAP-TLS ACK message 2024-04-01 18:30:24,666 [Th 35 Req 4779 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap_tls: ack handshake fragment handler 2024-04-01 18:30:24,666 [Th 35 Req 4779 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - eaptls_verify returned 1 2024-04-01 18:30:24,666 [Th 35 Req 4779 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - eaptls_process returned 13 2024-04-01 18:30:24,666 [Th 35 Req 4779 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: eap_compose returned 3 2024-04-01 18:30:24,666 [Th 35 Req 4779 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: eap_list_add EAP-State = 0x008c006e005800e0ab12000065d8b422d24f10b6 2024-04-01 18:30:24,666 [Th 35 Req 4779 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallauthenticate]: module "svc_3056_eap" returns handled for request 4779 2024-04-01 18:30:24,666 [Th 35 Req 4779 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: leaving group svc_3056_eap (returns handled) for request 4779 2024-04-01 18:30:24,666 [Th 35 Req 4779 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - The request contains following state_items 2024-04-01 18:30:24,666 [Th 35 Req 4779 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Service-State = 0x00a8003900810070ab1200002f5fa466dc3babdd026dbe4f3e08dfa2 2024-04-01 18:30:24,666 [Th 35 Req 4779 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - EAP-State = 0x008c006e005800e0ab12000065d8b422d24f10b6 2024-04-01 18:30:24,666 [Th 35 Req 4779 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - The request contains following session_id 2024-04-01 18:30:24,666 [Th 35 Req 4779 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Session-Id = "R0000003b-01-660ad310" 2024-04-01 18:30:24,666 [Th 35 Req 4779 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - The request contains following session messages 2024-04-01 18:30:24,666 [Th 35 Req 4779 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - The request contains following persistent config items 2024-04-01 18:30:24,666 [Th 35 Req 4779 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - User-Password = 2024-04-01 18:30:24,666 [Th 35 Req 4779 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Persisted-User-Name = "MedoB_Training" 2024-04-01 18:30:24,666 [Th 35 Req 4779 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Authentication-Source = "Local:localhost" 2024-04-01 18:30:24,666 [Th 35 Req 4779 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Authentication-Source-Name = "Endpoints Repository]" 2024-04-01 18:30:24,666 [Th 35 Req 4779 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Authentication-Source-Id = 4 2024-04-01 18:30:24,666 [Th 35 Req 4779 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - EAP-TLS-Version = "1.2" 2024-04-01 18:30:24,666 [Th 35 Req 4779 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Policy Evaluation Status: 0, Request Status: 0, Error Code: 201 2024-04-01 18:30:24,666 [Th 35 Req 4779 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - reqst_node_alloc: pkt info ptr - 0x5c01d750, pkt info size 16 2024-04-01 18:30:24,666 [Th 35 Req 4779 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - reqst_node_alloc: updated pkt info - pkt # 9 2024-04-01 18:30:24,666 [Th 35 Req 4779 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Sending Access-Challenge of id 147 to 10.2.200.32 port 1812 2024-04-01 18:30:24,666 [Th 35 Req 4779 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - EAP-Message = 0x010b02e60d00632e31283026060355040b131f536565207777772e656e74727573742e6e65742f6c6567616c2d7465726d7331393037060355040b1330286329203230303920456e74727573742c20496e632e202d20666f7220617574686f72697a656420757365206f6e6c793132303006035504031329456e747275737420526f6f742043657274696669636174696f6e20417574686f72697479202d20473200bd3081ba310b300906035504061302555331163014060355040a130d456e74727573742c20496e632e31283026060355040b131f536565207777772e656e74727573742e6e65742f6c6567616c2d7465726d733139303706035504 2024-04-01 18:30:24,666 [Th 35 Req 4779 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - EAP-Message = 0x0b1330286329203230313220456e74727573742c20496e632e202d20666f7220617574686f72697a656420757365206f6e6c79312e302c06035504031325456e74727573742043657274696669636174696f6e20417574686f72697479202d204c314b00be3081bb310b3009060355040613024359310b300906035504080c0243593111300f06035504070c084c696d6173736f6c31133011060355040a0c0a4d65646f6368656d6965310b3009060355040b0c0241503142304006035504030c394d65646f202d20417275626120426f73746f6e2053656375726520496e667261737472756374757265205369676e696e67204341e2809347313126 2024-04-01 18:30:24,666 [Th 35 Req 4779 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - EAP-Message = 0x302406092a864886f70d01090116176e657461646d696e406d65646f6368656d69652e636f6d00bb3081b8310b3009060355040613024359310b300906035504080c0243593111300f06035504070c084c696d6173736f6c31133011060355040a0c0a4d65646f6368656d6965310b3009060355040b0c024150313f303d06035504030c364d65646f202d20417275626120426f73746f6e2053656375726520496e66726173747275637475726520526f6f74204341e2809347313126302406092a864886f70d01090116176e657461646d696e406d65646f6368656d69652e636f6d16030300040e000000 2024-04-01 18:30:24,666 [Th 35 Req 4779 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Message-Authenticator = 0x00000000000000000000000000000000 2024-04-01 18:30:24,666 [Th 35 Req 4779 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - State = 0x414f6f417277424b41426d72456741417650587a373873663276596c44532b5a5467363147673d3d 2024-04-01 18:30:24,666 [Th 35 Req 4779 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - reqst_update_state node pkt info ptr 0x5c01d750, req cur pkt # 9, node cur pkt # 9 2024-04-01 18:30:24,666 [Th 35 Req 4779 SessId R0000003b-01-660ad310] INFO RadiusServer.Radius - reqst_update_state: Access-Challenge 147:828:48-4a-e9-c8-59-c4:AOoArwBKABmrEgAAvPXz78sf2vYlDS+ZTg61Gg== 2024-04-01 18:30:24,666 [Th 35 Req 4779 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Finished request 4779 2024-04-01 18:30:24,666 [Th 35 Req 4779 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Going to the next request 2024-04-01 18:30:24,717 [Th 37 Req 4780] DEBUG RadiusServer.Radius - Session-Id = "R0000003b-01-660ad310" 2024-04-01 18:30:24,717 [Th 37 Req 4780 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Processing the authorize section of radiusd.conf 2024-04-01 18:30:24,717 [Th 37 Req 4780 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: entering group authorize for request 4780 2024-04-01 18:30:24,717 [Th 37 Req 4780 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallauthorize]: module "dacl" returns noop for request 4780 2024-04-01 18:30:24,717 [Th 37 Req 4780 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_service: The request has Service-State attribute 2024-04-01 18:30:24,717 [Th 37 Req 4780 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_service: svcreq_list_find Service-State = 0x00a8003900810070ab1200002f5fa466dc3babdd026dbe4f3e08dfa2, Session-Id = "R0000003b-01-660ad310" 2024-04-01 18:30:24,717 [Th 37 Req 4780 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_service: Request found, released from the list 2024-04-01 18:30:24,717 [Th 37 Req 4780 SessId R0000003b-01-660ad310] INFO RadiusServer.Radius - rlm_service: The request was categorized into service "{ArubaOS SW} Wired Desktop DYN VLAN 802.1X" - 148:438:48-4a-e9-c8-59-c4 2024-04-01 18:30:24,717 [Th 37 Req 4780 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_service: Checking for username before "@" 2024-04-01 18:30:24,717 [Th 37 Req 4780 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_service: No delimiter. 2024-04-01 18:30:24,718 [Th 37 Req 4780 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_service: svcreq_list_add Service-State = 0x007d00eb005100c4ac12000069f12f78d7d71db9d4b79ddb4d96d857, Session-Id = "R0000003b-01-660ad310" 2024-04-01 18:30:24,718 [Th 37 Req 4780 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallauthorize]: module "service" returns ok for request 4780 2024-04-01 18:30:24,718 [Th 37 Req 4780 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: leaving group authorize (returns ok) for request 4780 2024-04-01 18:30:24,718 [Th 37 Req 4780 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Found Autz-Type svc_{ArubaOS SW} Wired Desktop DYN VLAN 802.1X_3056 2024-04-01 18:30:24,718 [Th 37 Req 4780 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Processing the authorize section of radiusd.conf 2024-04-01 18:30:24,718 [Th 37 Req 4780 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: entering group svc_{ArubaOS SW} Wired Desktop DYN VLAN 802.1X_3056 for request 4780 2024-04-01 18:30:24,718 [Th 37 Req 4780 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: entering group for request 4780 2024-04-01 18:30:24,718 [Th 37 Req 4780 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: entering redundant-sticky group for request 4780 2024-04-01 18:30:24,718 [Th 37 Req 4780 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Redundant-sticky: Module authsrc_3001 is active 2024-04-01 18:30:24,718 [Th 37 Req 4780 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_ldap: Request contains authsrc items, returning 2024-04-01 18:30:24,718 [Th 37 Req 4780 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallauthorize]: module "authsrc_3001" returns notfound for request 4780 2024-04-01 18:30:24,718 [Th 37 Req 4780 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: redundant-sticky group returns notfound for request 4780 2024-04-01 18:30:24,718 [Th 37 Req 4780 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_sql (authsrc_4): Request contains authsrc items, returning 2024-04-01 18:30:24,718 [Th 37 Req 4780 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallauthorize]: module "authsrc_4" returns ok for request 4780 2024-04-01 18:30:24,718 [Th 37 Req 4780 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: leaving group (returns ok) for request 4780 2024-04-01 18:30:24,718 [Th 37 Req 4780 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: Deleting Proxy-To-Realm and Post-Proxy-Type attributes 2024-04-01 18:30:24,718 [Th 37 Req 4780 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: EAP packet type response id 11 length 6 2024-04-01 18:30:24,718 [Th 37 Req 4780 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: No EAP Start, assuming it's an on-going EAP conversation 2024-04-01 18:30:24,718 [Th 37 Req 4780 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallauthorize]: module "svc_3056_eap" returns updated for request 4780 2024-04-01 18:30:24,718 [Th 37 Req 4780 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_auth_check: Allowed authentication methods: svc_3056_eap 2024-04-01 18:30:24,718 [Th 37 Req 4780 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - radius: No MS Identity VP 2024-04-01 18:30:24,718 [Th 37 Req 4780 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_auth_check: allowed Authentication method svc_3056_eap set. 2024-04-01 18:30:24,718 [Th 37 Req 4780 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallauthorize]: module "svc_3056_auth_check" returns ok for request 4780 2024-04-01 18:30:24,718 [Th 37 Req 4780 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: leaving group svc_{ArubaOS SW} Wired Desktop DYN VLAN 802.1X_3056 (returns updated) for request 4780 2024-04-01 18:30:24,718 [Th 37 Req 4780 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rad_check_password: Found Auth-Type svc_3056_eap 2024-04-01 18:30:24,718 [Th 37 Req 4780 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - auth: type "svc_3056_eap" 2024-04-01 18:30:24,718 [Th 37 Req 4780 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Processing the authenticate section of radiusd.conf 2024-04-01 18:30:24,718 [Th 37 Req 4780 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: entering group svc_3056_eap for request 4780 2024-04-01 18:30:24,718 [Th 37 Req 4780 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: eaplist_find EAP-State = 0x008c006e005800e0ab12000065d8b422d24f10b6 2024-04-01 18:30:24,718 [Th 37 Req 4780 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: Request found, released from the list 2024-04-01 18:30:24,718 [Th 37 Req 4780 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: EAP/tls 2024-04-01 18:30:24,718 [Th 37 Req 4780 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: processing type tls instance EAP TLS] 2024-04-01 18:30:24,718 [Th 37 Req 4780 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap_tls: Authenticate 2024-04-01 18:30:24,718 [Th 37 Req 4780 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap_tls: Request has authentication source Local:localhost 2024-04-01 18:30:24,718 [Th 37 Req 4780 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap_tls: processing TLS 2024-04-01 18:30:24,718 [Th 37 Req 4780 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap_tls: Received EAP-TLS ACK message 2024-04-01 18:30:24,718 [Th 37 Req 4780 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap_tls: ack handshake fragment handler 2024-04-01 18:30:24,718 [Th 37 Req 4780 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - eaptls_verify returned 1 2024-04-01 18:30:24,718 [Th 37 Req 4780 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - eaptls_process returned 13 2024-04-01 18:30:24,718 [Th 37 Req 4780 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: eap_compose returned 3 2024-04-01 18:30:24,719 [Th 37 Req 4780 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: eap_list_add EAP-State = 0x00fb00f60070004eac120000c103dbb7e7553a84 2024-04-01 18:30:24,719 [Th 37 Req 4780 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallauthenticate]: module "svc_3056_eap" returns handled for request 4780 2024-04-01 18:30:24,719 [Th 37 Req 4780 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: leaving group svc_3056_eap (returns handled) for request 4780 2024-04-01 18:30:24,719 [Th 37 Req 4780 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - The request contains following state_items 2024-04-01 18:30:24,719 [Th 37 Req 4780 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Service-State = 0x007d00eb005100c4ac12000069f12f78d7d71db9d4b79ddb4d96d857 2024-04-01 18:30:24,719 [Th 37 Req 4780 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - EAP-State = 0x00fb00f60070004eac120000c103dbb7e7553a84 2024-04-01 18:30:24,719 [Th 37 Req 4780 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - The request contains following session_id 2024-04-01 18:30:24,719 [Th 37 Req 4780 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Session-Id = "R0000003b-01-660ad310" 2024-04-01 18:30:24,719 [Th 37 Req 4780 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - The request contains following session messages 2024-04-01 18:30:24,719 [Th 37 Req 4780 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - The request contains following persistent config items 2024-04-01 18:30:24,719 [Th 37 Req 4780 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - User-Password = 2024-04-01 18:30:24,719 [Th 37 Req 4780 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Persisted-User-Name = "MedoB_Training" 2024-04-01 18:30:24,719 [Th 37 Req 4780 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Authentication-Source = "Local:localhost" 2024-04-01 18:30:24,719 [Th 37 Req 4780 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Authentication-Source-Name = "Endpoints Repository]" 2024-04-01 18:30:24,719 [Th 37 Req 4780 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Authentication-Source-Id = 4 2024-04-01 18:30:24,719 [Th 37 Req 4780 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - EAP-TLS-Version = "1.2" 2024-04-01 18:30:24,719 [Th 37 Req 4780 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Policy Evaluation Status: 0, Request Status: 0, Error Code: 201 2024-04-01 18:30:24,719 [Th 37 Req 4780 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - reqst_node_alloc: pkt info ptr - 0x5c01d750, pkt info size 16 2024-04-01 18:30:24,719 [Th 37 Req 4780 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - reqst_node_alloc: updated pkt info - pkt # 10 2024-04-01 18:30:24,719 [Th 37 Req 4780 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Sending Access-Challenge of id 148 to 10.2.200.32 port 1812 2024-04-01 18:30:24,719 [Th 37 Req 4780 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - EAP-Message = 0x010c000a0d8000000000 2024-04-01 18:30:24,719 [Th 37 Req 4780 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Message-Authenticator = 0x00000000000000000000000000000000 2024-04-01 18:30:24,719 [Th 37 Req 4780 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - State = 0x414a6b413277424d414e697345674141496c647a4c456d792f63614a3732373241426c7053413d3d 2024-04-01 18:30:24,719 [Th 37 Req 4780 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - reqst_update_state node pkt info ptr 0x5c01d750, req cur pkt # 10, node cur pkt # 10 2024-04-01 18:30:24,719 [Th 37 Req 4780 SessId R0000003b-01-660ad310] INFO RadiusServer.Radius - reqst_update_state: Access-Challenge 148:92:48-4a-e9-c8-59-c4:AJkA2wBMANisEgAAIldzLEmy/caJ7272ABlpSA== 2024-04-01 18:30:24,719 [Th 37 Req 4780 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Finished request 4780 2024-04-01 18:30:24,719 [Th 37 Req 4780 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Going to the next request 2024-04-01 18:30:24,723 [Th 38 Req 4781] DEBUG RadiusServer.Radius - Session-Id = "R0000003b-01-660ad310" 2024-04-01 18:30:24,723 [Th 38 Req 4781 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Processing the authorize section of radiusd.conf 2024-04-01 18:30:24,723 [Th 38 Req 4781 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: entering group authorize for request 4781 2024-04-01 18:30:24,723 [Th 38 Req 4781 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallauthorize]: module "dacl" returns noop for request 4781 2024-04-01 18:30:24,723 [Th 38 Req 4781 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_service: The request has Service-State attribute 2024-04-01 18:30:24,724 [Th 38 Req 4781 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_service: svcreq_list_find Service-State = 0x007d00eb005100c4ac12000069f12f78d7d71db9d4b79ddb4d96d857, Session-Id = "R0000003b-01-660ad310" 2024-04-01 18:30:24,724 [Th 38 Req 4781 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_service: Request found, released from the list 2024-04-01 18:30:24,724 [Th 38 Req 4781 SessId R0000003b-01-660ad310] INFO RadiusServer.Radius - rlm_service: The request was categorized into service "{ArubaOS SW} Wired Desktop DYN VLAN 802.1X" - 149:438:48-4a-e9-c8-59-c4 2024-04-01 18:30:24,724 [Th 38 Req 4781 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_service: Checking for username before "@" 2024-04-01 18:30:24,724 [Th 38 Req 4781 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_service: No delimiter. 2024-04-01 18:30:24,724 [Th 38 Req 4781 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_service: svcreq_list_add Service-State = 0x0040002f00fb00c3ad120000013cd087ed7636c3410ca45725a2fff8, Session-Id = "R0000003b-01-660ad310" 2024-04-01 18:30:24,724 [Th 38 Req 4781 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallauthorize]: module "service" returns ok for request 4781 2024-04-01 18:30:24,724 [Th 38 Req 4781 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: leaving group authorize (returns ok) for request 4781 2024-04-01 18:30:24,724 [Th 38 Req 4781 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Found Autz-Type svc_{ArubaOS SW} Wired Desktop DYN VLAN 802.1X_3056 2024-04-01 18:30:24,724 [Th 38 Req 4781 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Processing the authorize section of radiusd.conf 2024-04-01 18:30:24,724 [Th 38 Req 4781 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: entering group svc_{ArubaOS SW} Wired Desktop DYN VLAN 802.1X_3056 for request 4781 2024-04-01 18:30:24,724 [Th 38 Req 4781 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: entering group for request 4781 2024-04-01 18:30:24,724 [Th 38 Req 4781 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: entering redundant-sticky group for request 4781 2024-04-01 18:30:24,724 [Th 38 Req 4781 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Redundant-sticky: Module authsrc_3001 is active 2024-04-01 18:30:24,724 [Th 38 Req 4781 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_ldap: Request contains authsrc items, returning 2024-04-01 18:30:24,724 [Th 38 Req 4781 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallauthorize]: module "authsrc_3001" returns notfound for request 4781 2024-04-01 18:30:24,724 [Th 38 Req 4781 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: redundant-sticky group returns notfound for request 4781 2024-04-01 18:30:24,724 [Th 38 Req 4781 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_sql (authsrc_4): Request contains authsrc items, returning 2024-04-01 18:30:24,724 [Th 38 Req 4781 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallauthorize]: module "authsrc_4" returns ok for request 4781 2024-04-01 18:30:24,724 [Th 38 Req 4781 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: leaving group (returns ok) for request 4781 2024-04-01 18:30:24,724 [Th 38 Req 4781 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: Deleting Proxy-To-Realm and Post-Proxy-Type attributes 2024-04-01 18:30:24,724 [Th 38 Req 4781 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: EAP packet type response id 12 length 6 2024-04-01 18:30:24,724 [Th 38 Req 4781 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: No EAP Start, assuming it's an on-going EAP conversation 2024-04-01 18:30:24,724 [Th 38 Req 4781 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallauthorize]: module "svc_3056_eap" returns updated for request 4781 2024-04-01 18:30:24,724 [Th 38 Req 4781 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_auth_check: Allowed authentication methods: svc_3056_eap 2024-04-01 18:30:24,724 [Th 38 Req 4781 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - radius: No MS Identity VP 2024-04-01 18:30:24,724 [Th 38 Req 4781 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_auth_check: allowed Authentication method svc_3056_eap set. 2024-04-01 18:30:24,724 [Th 38 Req 4781 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallauthorize]: module "svc_3056_auth_check" returns ok for request 4781 2024-04-01 18:30:24,724 [Th 38 Req 4781 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: leaving group svc_{ArubaOS SW} Wired Desktop DYN VLAN 802.1X_3056 (returns updated) for request 4781 2024-04-01 18:30:24,724 [Th 38 Req 4781 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rad_check_password: Found Auth-Type svc_3056_eap 2024-04-01 18:30:24,724 [Th 38 Req 4781 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - auth: type "svc_3056_eap" 2024-04-01 18:30:24,724 [Th 38 Req 4781 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Processing the authenticate section of radiusd.conf 2024-04-01 18:30:24,724 [Th 38 Req 4781 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: entering group svc_3056_eap for request 4781 2024-04-01 18:30:24,724 [Th 38 Req 4781 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: eaplist_find EAP-State = 0x00fb00f60070004eac120000c103dbb7e7553a84 2024-04-01 18:30:24,724 [Th 38 Req 4781 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: Request found, released from the list 2024-04-01 18:30:24,724 [Th 38 Req 4781 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: EAP/tls 2024-04-01 18:30:24,724 [Th 38 Req 4781 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: processing type tls instance EAP TLS] 2024-04-01 18:30:24,724 [Th 38 Req 4781 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap_tls: Authenticate 2024-04-01 18:30:24,724 [Th 38 Req 4781 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap_tls: Request has authentication source Local:localhost 2024-04-01 18:30:24,724 [Th 38 Req 4781 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap_tls: processing TLS 2024-04-01 18:30:24,725 [Th 38 Req 4781 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap_tls: Received EAP-TLS ACK message 2024-04-01 18:30:24,725 [Th 38 Req 4781 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap_tls: ack handshake fragment handler 2024-04-01 18:30:24,725 [Th 38 Req 4781 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - eaptls_verify returned 1 2024-04-01 18:30:24,725 [Th 38 Req 4781 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - eaptls_process returned 13 2024-04-01 18:30:24,725 [Th 38 Req 4781 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: eap_compose returned 3 2024-04-01 18:30:24,725 [Th 38 Req 4781 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_eap: eap_list_add EAP-State = 0x0059002c001d00cbad120000124e6057be22eddb 2024-04-01 18:30:24,725 [Th 38 Req 4781 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallauthenticate]: module "svc_3056_eap" returns handled for request 4781 2024-04-01 18:30:24,725 [Th 38 Req 4781 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: leaving group svc_3056_eap (returns handled) for request 4781 2024-04-01 18:30:24,725 [Th 38 Req 4781 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - The request contains following state_items 2024-04-01 18:30:24,725 [Th 38 Req 4781 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Service-State = 0x0040002f00fb00c3ad120000013cd087ed7636c3410ca45725a2fff8 2024-04-01 18:30:24,725 [Th 38 Req 4781 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - EAP-State = 0x0059002c001d00cbad120000124e6057be22eddb 2024-04-01 18:30:24,725 [Th 38 Req 4781 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - The request contains following session_id 2024-04-01 18:30:24,725 [Th 38 Req 4781 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Session-Id = "R0000003b-01-660ad310" 2024-04-01 18:30:24,725 [Th 38 Req 4781 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - The request contains following session messages 2024-04-01 18:30:24,725 [Th 38 Req 4781 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - The request contains following persistent config items 2024-04-01 18:30:24,725 [Th 38 Req 4781 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - User-Password = 2024-04-01 18:30:24,725 [Th 38 Req 4781 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Persisted-User-Name = "MedoB_Training" 2024-04-01 18:30:24,725 [Th 38 Req 4781 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Authentication-Source = "Local:localhost" 2024-04-01 18:30:24,725 [Th 38 Req 4781 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Authentication-Source-Name = "Endpoints Repository]" 2024-04-01 18:30:24,725 [Th 38 Req 4781 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Authentication-Source-Id = 4 2024-04-01 18:30:24,725 [Th 38 Req 4781 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - EAP-TLS-Version = "1.2" 2024-04-01 18:30:24,725 [Th 38 Req 4781 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Policy Evaluation Status: 0, Request Status: 0, Error Code: 201 2024-04-01 18:30:24,725 [Th 38 Req 4781 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - reqst_node_alloc: pkt info ptr - 0x5c01d750, pkt info size 16 2024-04-01 18:30:24,725 [Th 38 Req 4781 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - reqst_node_alloc: updated pkt info - pkt # 11 2024-04-01 18:30:24,725 [Th 38 Req 4781 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Sending Access-Challenge of id 149 to 10.2.200.32 port 1812 2024-04-01 18:30:24,725 [Th 38 Req 4781 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - EAP-Message = 0x010d000a0d8000000000 2024-04-01 18:30:24,725 [Th 38 Req 4781 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Message-Authenticator = 0x00000000000000000000000000000000 2024-04-01 18:30:24,725 [Th 38 Req 4781 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - State = 0x414c4d4156774368414d4f744567414178796f384f515a7a38732f47696c77782b6f6d7447773d3d 2024-04-01 18:30:24,725 [Th 38 Req 4781 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - reqst_update_state node pkt info ptr 0x5c01d750, req cur pkt # 11, node cur pkt # 11 2024-04-01 18:30:24,725 [Th 38 Req 4781 SessId R0000003b-01-660ad310] INFO RadiusServer.Radius - reqst_update_state: Access-Challenge 149:92:48-4a-e9-c8-59-c4:ALMAVwChAMOtEgAAxyo8OQZz8s/Gilwx+omtGw== 2024-04-01 18:30:24,725 [Th 38 Req 4781 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Finished request 4781 2024-04-01 18:30:24,725 [Th 38 Req 4781 SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Going to the next request 2024-04-01 18:31:11,326 [main SessId R0000003b-01-660ad310] ERROR RadiusServer.Radius - reqst_clean_list: Deleting request sessid - R0000003b-01-660ad310, state - ALMAVwChAMOtEgAAxyo8OQZz8s/Gilwx+omtGw= 2024-04-01 18:31:11,326 [main SessId R0000003b-01-660ad310] ERROR RadiusServer.Radius - reqst_clean_list: Packet 138:409:88:48-4a-e9-c8-59-c4 recv 1711985424.593825 - resp 1711985424.611646 2024-04-01 18:31:11,326 [main SessId R0000003b-01-660ad310] ERROR RadiusServer.Radius - reqst_clean_list: Packet 139:438:88:48-4a-e9-c8-59-c4 recv 1711985424.614246 - resp 1711985424.617676 2024-04-01 18:31:11,326 [main SessId R0000003b-01-660ad310] ERROR RadiusServer.Radius - reqst_clean_list: Packet 140:522:1124:48-4a-e9-c8-59-c4 recv 1711985424.625507 - resp 1711985424.630296 2024-04-01 18:31:11,327 [main SessId R0000003b-01-660ad310] ERROR RadiusServer.Radius - reqst_clean_list: Packet 141:438:1120:48-4a-e9-c8-59-c4 recv 1711985424.632825 - resp 1711985424.636462 2024-04-01 18:31:11,327 [main SessId R0000003b-01-660ad310] ERROR RadiusServer.Radius - reqst_clean_list: Packet 142:438:1120:48-4a-e9-c8-59-c4 recv 1711985424.638860 - resp 1711985424.642726 2024-04-01 18:31:11,327 [main SessId R0000003b-01-660ad310] ERROR RadiusServer.Radius - reqst_clean_list: Packet 143:438:1120:48-4a-e9-c8-59-c4 recv 1711985424.645079 - resp 1711985424.646566 2024-04-01 18:31:11,327 [main SessId R0000003b-01-660ad310] ERROR RadiusServer.Radius - reqst_clean_list: Packet 144:438:1120:48-4a-e9-c8-59-c4 recv 1711985424.648903 - resp 1711985424.652639 2024-04-01 18:31:11,327 [main SessId R0000003b-01-660ad310] ERROR RadiusServer.Radius - reqst_clean_list: Packet 145:438:1120:48-4a-e9-c8-59-c4 recv 1711985424.654913 - resp 1711985424.658716 2024-04-01 18:31:11,327 [main SessId R0000003b-01-660ad310] ERROR RadiusServer.Radius - reqst_clean_list: Packet 146:438:1120:48-4a-e9-c8-59-c4 recv 1711985424.661221 - resp 1711985424.662764 2024-04-01 18:31:11,327 [main SessId R0000003b-01-660ad310] ERROR RadiusServer.Radius - reqst_clean_list: Packet 147:438:828:48-4a-e9-c8-59-c4 recv 1711985424.665086 - resp 1711985424.666441 2024-04-01 18:31:11,327 [main SessId R0000003b-01-660ad310] ERROR RadiusServer.Radius - reqst_clean_list: Packet 148:438:92:48-4a-e9-c8-59-c4 recv 1711985424.716257 - resp 1711985424.719630 2024-04-01 18:31:11,327 [main SessId R0000003b-01-660ad310] ERROR RadiusServer.Radius - reqst_clean_list: Packet 149:438:92:48-4a-e9-c8-59-c4 recv 1711985424.722242 - resp 1711985424.725701 2024-04-01 18:31:11,327 [main SessId R0000003b-01-660ad310] INFO RadiusServer.Radius - Last EAP Packet Processing Time = 3 ms 2024-04-01 18:31:11,327 [main SessId R0000003b-01-660ad310] DEBUG StatsDClient.StatsClient - Formatted StatsD data=default.cynac1.radius.timedoutpkt.count:1|c 2024-04-01 18:31:11,327 [main SessId R0000003b-01-660ad310] DEBUG StatsDClient.StatsClient - Sending StatsD request=default.cynac1.radius.timedoutpkt.count:1|c 2024-04-01 18:31:11,327 [main SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - adding alert message Last EAP Packet Processing Time = 3 ms 2024-04-01 18:31:11,328 [main SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Found Post-Auth-Type 2024-04-01 18:31:11,328 [main SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Processing the post-auth section of radiusd.conf 2024-04-01 18:31:11,328 [main SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: entering group REJECT for request 0 2024-04-01 18:31:11,328 [main SessId R0000003b-01-660ad310] INFO RadiusServer.Radius - rlm_policy: Starting Policy Evaluation. 2024-04-01 18:31:11,328 [main SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_policy: policy_get_polsvr_conn: Checking Id: 0 2024-04-01 18:31:11,328 [main SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_policy: policy_get_polsvr_conn: Got Id: 0, handle: 0x1729a50 2024-04-01 18:31:11,328 [main SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_policy: policy_add_request_vps 2024-04-01 18:31:11,328 [main SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Framed-MTU = 3038 2024-04-01 18:31:11,328 [main SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - NAS-IP-Address = 10.2.200.32 2024-04-01 18:31:11,328 [main SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - NAS-Identifier = "MedoB-Entrance" 2024-04-01 18:31:11,328 [main SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - User-Name = "MedoB_Training" 2024-04-01 18:31:11,328 [main SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Service-Type = Framed-User 2024-04-01 18:31:11,328 [main SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Framed-Protocol = PPP 2024-04-01 18:31:11,329 [main SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - NAS-Port = 29 2024-04-01 18:31:11,329 [main SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - NAS-Port-Type = Ethernet 2024-04-01 18:31:11,329 [main SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - NAS-Port-Id = "1/29" 2024-04-01 18:31:11,329 [main SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Called-Station-Id = "38-10-f0-54-37-ca" 2024-04-01 18:31:11,329 [main SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Calling-Station-Id = "48-4a-e9-c8-59-c4" 2024-04-01 18:31:11,329 [main SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Connect-Info = "CONNECT Ethernet 1000Mbps Full duplex" 2024-04-01 18:31:11,329 [main SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Tunnel-Type:0 = VLAN 2024-04-01 18:31:11,329 [main SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Tunnel-Medium-Type:0 = IEEE-802 2024-04-01 18:31:11,329 [main SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Tunnel-Private-Group-Id:0 = "100" 2024-04-01 18:31:11,329 [main SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_policy: skipping attribute EAP-Message in policy_add_request_vps 2024-04-01 18:31:11,329 [main SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_policy: skipping attribute Message-Authenticator in policy_add_request_vps 2024-04-01 18:31:11,329 [main SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - MS-RAS-Vendor = 11 2024-04-01 18:31:11,329 [main SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - HPE-Capability-Advertisement = "??" 2024-04-01 18:31:11,329 [main SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - HPE-Capability-Advertisement = "??" 2024-04-01 18:31:11,329 [main SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - HPE-Capability-Advertisement = "??" 2024-04-01 18:31:11,329 [main SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - HPE-Capability-Advertisement = "??" 2024-04-01 18:31:11,329 [main SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - HPE-Capability-Advertisement = "??" 2024-04-01 18:31:11,329 [main SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - HPE-Capability-Advertisement = "??" 2024-04-01 18:31:11,330 [main SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - HPE-Capability-Advertisement = "??" 2024-04-01 18:31:11,330 [main SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - HPE-Capability-Advertisement = "??" 2024-04-01 18:31:11,330 [main SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - HPE-Capability-Advertisement = "?8" 2024-04-01 18:31:11,330 [main SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - HPE-Capability-Advertisement = "?:" 2024-04-01 18:31:11,330 [main SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - HPE-Capability-Advertisement = "?@" 2024-04-01 18:31:11,330 [main SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - HPE-Capability-Advertisement = "?A" 2024-04-01 18:31:11,330 [main SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - HPE-Capability-Advertisement = "?Q" 2024-04-01 18:31:11,330 [main SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_policy: policy_add_config_vps - Request has the following config items 2024-04-01 18:31:11,330 [main SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Session-Id = "R0000003b-01-660ad310" 2024-04-01 18:31:11,330 [main SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - User-Password = 2024-04-01 18:31:11,330 [main SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Persisted-User-Name = "MedoB_Training" 2024-04-01 18:31:11,330 [main SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Authentication-Source = "Local:localhost" 2024-04-01 18:31:11,330 [main SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Authentication-Source-Name = "Endpoints Repository]" 2024-04-01 18:31:11,330 [main SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Authentication-Source-Id = 4 2024-04-01 18:31:11,330 [main SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - EAP-TLS-Version = "1.2" 2024-04-01 18:31:11,330 [main SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Service-Name = "{ArubaOS SW} Wired Desktop DYN VLAN 802.1X" 2024-04-01 18:31:11,330 [main SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Service-Id = 3056 2024-04-01 18:31:11,330 [main SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Autz-Type = svc_{ArubaOS SW} Wired Desktop DYN VLAN 802.1X_3056 2024-04-01 18:31:11,330 [main SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Auth-Type = svc_3056_eap 2024-04-01 18:31:11,330 [main SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Authentication-EAP-Method = "tls" 2024-04-01 18:31:11,330 [main SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Authentication-Method = "EAP" 2024-04-01 18:31:11,330 [main SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Post-Auth-Type = REJECT 2024-04-01 18:31:11,330 [main SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Service-Name = "{ArubaOS SW} Wired Desktop DYN VLAN 802.1X" 2024-04-01 18:31:11,330 [main SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Session-Id = "R0000003b-01-660ad310" 2024-04-01 18:31:11,331 [main SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Authentication-Source-Id = 4 2024-04-01 18:31:11,331 [main SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_policy: policy_add_reply_vps 2024-04-01 18:31:11,331 [main SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_policy: policy_add_conn_info 2024-04-01 18:31:11,331 [main SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_policy: Adding Connection:Src-IP-Address=10.2.200.32 2024-04-01 18:31:11,331 [main SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_policy: Adding Connection:NAD-IP-Address=10.2.200.32 2024-04-01 18:31:11,331 [main SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_policy: Adding Connection:Dest-IP-Address=10.2.0.60 2024-04-01 18:31:11,331 [main SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_policy: policy_add_authentication_attributes 2024-04-01 18:31:11,331 [main SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_policy: not computed Authentication:TLS-Version 2024-04-01 18:31:11,331 [main SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_policy: policy_add_authorization_attributes 2024-04-01 18:31:11,331 [main SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_policy: policy_add_certificate_attributes 2024-04-01 18:31:11,331 [main SessId R0000003b-01-660ad310] DEBUG StatsDClient.StatsClient - Formatted StatsD data=default.cynac1.radius.auth._Endpoints_Repository_.failure:1|c 2024-04-01 18:31:11,331 [main SessId R0000003b-01-660ad310] DEBUG StatsDClient.StatsClient - Sending StatsD request=default.cynac1.radius.auth._Endpoints_Repository_.failure:1|c 2024-04-01 18:31:11,331 [main SessId R0000003b-01-660ad310] DEBUG StatsDClient.StatsClient - Formatted StatsD data=default.cynac1.radius.auth.failure:1|c 2024-04-01 18:31:11,331 [main SessId R0000003b-01-660ad310] DEBUG StatsDClient.StatsClient - Sending StatsD request=default.cynac1.radius.auth.failure:1|c 2024-04-01 18:31:11,332 [main SessId R0000003b-01-660ad310] DEBUG StatsDClient.StatsClient - Formatted StatsD data=default.cynac1.radius.auth._Endpoints_Repository_.count:1|c 2024-04-01 18:31:11,332 [main SessId R0000003b-01-660ad310] DEBUG StatsDClient.StatsClient - Sending StatsD request=default.cynac1.radius.auth._Endpoints_Repository_.count:1|c 2024-04-01 18:31:11,332 [main SessId R0000003b-01-660ad310] DEBUG StatsDClient.StatsClient - Formatted StatsD data=default.cynac1.radius.auth.count:1|c 2024-04-01 18:31:11,332 [main SessId R0000003b-01-660ad310] DEBUG StatsDClient.StatsClient - Sending StatsD request=default.cynac1.radius.auth.count:1|c 2024-04-01 18:31:11,337 [RequestHandler-1-0x7f2883fff700 r=psauto-1711690116-69432 h=239 r=R0000003b-01-660ad310] INFO Common.EndpointTable - Returning EndpointSPtr for macAddr 484ae9c859c4 2024-04-01 18:31:11,337 [RequestHandler-1-0x7f2883fff700 r=psauto-1711690116-69432 h=239 r=R0000003b-01-660ad310] INFO Common.TagDefinitionCacheTable - No InstanceTagDefCacheMap found for instance id = 3063 entity id = 29 2024-04-01 18:31:11,338 [RequestHandler-1-0x7f2883fff700 r=psauto-1711690116-69432 h=239 r=R0000003b-01-660ad310] INFO Common.TagDefinitionCacheTable - Building the TagDefMapTable for NAD instance=3063 2024-04-01 18:31:11,338 [RequestHandler-1-0x7f2883fff700 r=psauto-1711690116-69432 h=239 r=R0000003b-01-660ad310] INFO Common.TagDefinitionCacheTable - Built 0 tag(s) for NAD instanceId=3063|entityId=29 2024-04-01 18:31:11,338 [RequestHandler-1-0x7f2883fff700 r=psauto-1711690116-69432 h=239 r=R0000003b-01-660ad310] INFO TAT.TagAttrHolderBuilder - No tags built for instanceId=3063|entity=Device 2024-04-01 18:31:11,338 [RequestHandler-1-0x7f2883fff700 r=psauto-1711690116-69432 h=239 r=R0000003b-01-660ad310] INFO TAT.AluTagAttrHolderBuilder - buildAttrHolder: Tags cannot be built for instanceId=0 (NULL AuthLocalUser) 2024-04-01 18:31:11,338 [RequestHandler-1-0x7f2883fff700 r=psauto-1711690116-69432 h=239 r=R0000003b-01-660ad310] INFO TAT.GuTagAttrHolderBuilder - buildAttrHolder: Tags cannot be built for instanceId=0 (NULL GuestUser) 2024-04-01 18:31:11,338 [RequestHandler-1-0x7f2883fff700 r=psauto-1711690116-69432 h=239 r=R0000003b-01-660ad310] INFO TAT.OnboardTagAttrHolderBuilder - buildAttrHolder: Tags cannot be built for instanceId=0 (NULL Onboard Device User) 2024-04-01 18:31:11,338 [RequestHandler-1-0x7f2883fff700 h=581754 c=R0000003b-01-660ad310] INFO Core.PETaskScheduler - *** PE_TASK_SCHEDULE_RADIUS Started *** 2024-04-01 18:31:11,338 [RequestHandler-1-0x7f2883fff700 h=581754 c=R0000003b-01-660ad310] INFO Core.PETaskScheduler - ** Starting PETaskAuthSourceRestriction ** 2024-04-01 18:31:11,339 [RequestHandler-1-0x7f2883fff700 h=581754 c=R0000003b-01-660ad310] INFO Core.PETaskScheduler - ** Starting PETaskRoleMapping ** 2024-04-01 18:31:11,341 [RequestHandler-1-0x7f2883fff700 r=R0000003b-01-660ad310 h=581754 c=R0000003b-01-660ad310] INFO Core.PETaskScheduler - ** Completed PETaskAuthSourceRestriction ** 2024-04-01 18:31:11,345 [RequestHandler-1-0x7f2883fff700 h=581756 c=R0000003b-01-660ad310] INFO Core.PETaskRoleMapping - Roles: Medo - Aruba Access Point, MedoB-Entrance Area 2024-04-01 18:31:11,346 [RequestHandler-1-0x7f2883fff700 r=R0000003b-01-660ad310 h=581754 c=R0000003b-01-660ad310] INFO Core.PETaskScheduler - ** Completed PETaskRoleMapping ** 2024-04-01 18:31:11,346 [RequestHandler-1-0x7f2883fff700 r=R0000003b-01-660ad310 h=581754 c=R0000003b-01-660ad310] INFO Core.PETaskScheduler - ** Starting PETaskPolicyResult ** 2024-04-01 18:31:11,347 [RequestHandler-1-0x7f2883fff700 r=R0000003b-01-660ad310 h=581754 c=R0000003b-01-660ad310] INFO Core.PETaskScheduler - ** Completed PETaskPolicyResult ** 2024-04-01 18:31:11,347 [RequestHandler-1-0x7f2883fff700 r=R0000003b-01-660ad310 h=581754 c=R0000003b-01-660ad310] INFO Core.PETaskScheduler - ** Starting PETaskEnforcement ** 2024-04-01 18:31:11,348 [RequestHandler-1-0x7f2883fff700 h=581759 c=R0000003b-01-660ad310] INFO Core.PETaskEnforcement - EnfProfiles: Update L-Known Loc {Aruba}, Update Endpoint Known], Medo VL(100){Aruba-AP} DUR 2024-04-01 18:31:11,349 [RequestHandler-1-0x7f2883fff700 r=R0000003b-01-660ad310 h=581754 c=R0000003b-01-660ad310] INFO Core.PETaskScheduler - ** Completed PETaskEnforcement ** 2024-04-01 18:31:11,349 [RequestHandler-1-0x7f2883fff700 r=R0000003b-01-660ad310 h=581754 c=R0000003b-01-660ad310] INFO Core.PETaskScheduler - ** Starting PETaskRadiusEnfProfileBuilder ** 2024-04-01 18:31:11,349 [RequestHandler-1-0x7f2883fff700 r=R0000003b-01-660ad310 h=581754 c=R0000003b-01-660ad310] INFO Core.PETaskScheduler - ** Starting PETaskRadiusCoAEnfProfileBuilder ** 2024-04-01 18:31:11,349 [RequestHandler-1-0x7f2883fff700 r=R0000003b-01-660ad310 h=581754 c=R0000003b-01-660ad310] INFO Core.PETaskScheduler - ** Starting PETaskAppEnfProfileBuilder ** 2024-04-01 18:31:11,349 [RequestHandler-1-0x7f2883fff700 r=R0000003b-01-660ad310 h=581754 c=R0000003b-01-660ad310] INFO Core.PETaskScheduler - ** Starting PETaskAgentEnfProfileBuilder ** 2024-04-01 18:31:11,349 [RequestHandler-1-0x7f2883fff700 r=R0000003b-01-660ad310 h=581754 c=R0000003b-01-660ad310] INFO Core.PETaskScheduler - ** Starting PETaskPostAuthEnfProfileBuilder ** 2024-04-01 18:31:11,349 [RequestHandler-1-0x7f2883fff700 r=R0000003b-01-660ad310 h=581754 c=R0000003b-01-660ad310] INFO Core.PETaskScheduler - ** Starting PETaskGenericEnfProfileBuilder ** 2024-04-01 18:31:11,350 [RequestHandler-1-0x7f2883fff700 h=581765 c=R0000003b-01-660ad310] INFO Core.PETaskGenericEnfProfileBuilder - getApplicableProfiles: No App enforcement (Generic) profiles applicable for this device 2024-04-01 18:31:11,350 [RequestHandler-1-0x7f2883fff700 h=581762 c=R0000003b-01-660ad310] WARN Common.AppEnfProfileTable - getAppType: Failed for id=3144 2024-04-01 18:31:11,350 [RequestHandler-1-0x7f2883fff700 h=581762 c=R0000003b-01-660ad310] WARN Common.AppEnfProfileTable - getAppType: Failed for id=51 2024-04-01 18:31:11,351 [RequestHandler-1-0x7f2883fff700 h=581760 c=R0000003b-01-660ad310] INFO Core.PETaskRadiusEnfProfileBuilder - EnfProfileAction=ACCEPT 2024-04-01 18:31:11,351 [RequestHandler-1-0x7f2883fff700 h=581760 c=R0000003b-01-660ad310] INFO Core.PETaskRadiusEnfProfileBuilder - Radius enfProfiles used: Medo VL(100){Aruba-AP} DUR 2024-04-01 18:31:11,351 [RequestHandler-1-0x7f2883fff700 h=581760 c=R0000003b-01-660ad310] INFO Core.EnfProfileComputer - getFinalSessionTimeout: sessionTimeout = 0 2024-04-01 18:31:11,351 [RequestHandler-1-0x7f2883fff700 r=R0000003b-01-660ad310 h=581754 c=R0000003b-01-660ad310] INFO Core.PETaskScheduler - ** Completed PETaskGenericEnfProfileBuilder ** 2024-04-01 18:31:11,351 [RequestHandler-1-0x7f2883fff700 r=R0000003b-01-660ad310 h=581754 c=R0000003b-01-660ad310] INFO Core.PETaskScheduler - ** Completed PETaskAgentEnfProfileBuilder ** 2024-04-01 18:31:11,352 [RequestHandler-1-0x7f2883fff700 r=R0000003b-01-660ad310 h=581754 c=R0000003b-01-660ad310] INFO Core.PETaskScheduler - ** Completed PETaskAppEnfProfileBuilder ** 2024-04-01 18:31:11,352 [RequestHandler-1-0x7f2883fff700 r=R0000003b-01-660ad310 h=581754 c=R0000003b-01-660ad310] INFO Core.PETaskScheduler - ** Starting PETaskCliEnforcement ** 2024-04-01 18:31:11,352 [RequestHandler-1-0x7f2883fff700 h=581766 c=R0000003b-01-660ad310] INFO Core.PETaskCliEnforcement - startHandler: No commands for CLI enforcement 2024-04-01 18:31:11,352 [RequestHandler-1-0x7f2883fff700 r=R0000003b-01-660ad310 h=581764 c=R0000003b-01-660ad310] INFO Core.PETaskPostAuthEnfProfileBuilder - Post auth enforcement profiles used: Update L-Known Loc {Aruba}, Update Endpoint Known] 2024-04-01 18:31:11,352 [RequestHandler-1-0x7f2883fff700 r=R0000003b-01-660ad310 h=581764 c=R0000003b-01-660ad310] INFO Core.PETaskPostAuthEnfProfileBuilder - UnknownAutzParams to fetch for PostAuthEnfProfiles: : 2024-04-01 18:31:11,352 [RequestHandler-1-0x7f2883fff700 r=R0000003b-01-660ad310 h=581764 c=R0000003b-01-660ad310] INFO Core.PETaskPostAuthEnfProfileBuilder - UnknownNAutzParams to fetch for PostAuthEnfProfiles: : Radius:IETF:NAS-Identifier, Radius:IETF:NAS-Port 2024-04-01 18:31:11,352 [RequestHandler-1-0x7f2883fff700 r=R0000003b-01-660ad310 h=581764 c=R0000003b-01-660ad310] INFO Core.PETaskPostAuthEnfProfileBuilder - Discarding attr name=Endpoint:Last Known Location|attr value=MedoB-Entrance:29 as the entity = 484ae9c859c4 already possesses this value 2024-04-01 18:31:11,352 [RequestHandler-1-0x7f2883fff700 r=R0000003b-01-660ad310 h=581764 c=R0000003b-01-660ad310] INFO Common.EndpointTable - Returning EndpointSPtr for macAddr 484ae9c859c4 2024-04-01 18:31:11,352 [RequestHandler-1-0x7f2883fff700 r=R0000003b-01-660ad310 h=581764 c=R0000003b-01-660ad310] INFO Core.PETaskPostAuthEnfProfileBuilder - Discarding attr name=Status-Update:Endpoint|attr value=Known as the entity = 484ae9c859c4 already possesses this value 2024-04-01 18:31:11,352 [RequestHandler-1-0x7f2883fff700 r=R0000003b-01-660ad310 h=581764 c=R0000003b-01-660ad310] INFO Core.PETaskPostAuthEnfProfileBuilder - sendPostAuthHTTPRequest: Sending PostAuthEnfRequest {"content":{"auth_source_id":0,"mac_address":"484ae9c859c4","nas_ip":"10.2.200.32","post_auth_actions":{"enf_profile_name":"Update L-Known Loc {Aruba}","enf_profile_type":"EntityUpdate","params":null},{"enf_profile_name":"Update Endpoint Known]","enf_profile_type":"EntityUpdate","params":null}],"user_id":"MedoB_Training"},"id":"R0000002c-01-660ad254","name":"pactrl_enf_request"} 2024-04-01 18:31:11,352 [RequestHandler-1-0x7f2883fff700 r=R0000003b-01-660ad310 h=581764 c=R0000003b-01-660ad310] INFO Core.PETaskPostAuthEnfProfileBuilder - sendPostAuthResponse: Done sending the PostAuthEnfRequest 2024-04-01 18:31:11,352 [RequestHandler-1-0x7f2883fff700 r=R0000003b-01-660ad310 h=581754 c=R0000003b-01-660ad310] INFO Core.PETaskScheduler - ** Completed PETaskRadiusEnfProfileBuilder ** 2024-04-01 18:31:11,353 [RequestHandler-1-0x7f2883fff700 r=R0000003b-01-660ad310 h=581761 c=R0000003b-01-660ad310] INFO Core.PETaskRadiusCoAEnfProfileBuilder - getApplicableProfiles: No radius_coa enforcement profiles applicable for this device 2024-04-01 18:31:11,353 [RequestHandler-1-0x7f2883fff700 r=R0000003b-01-660ad310 h=581754 c=R0000003b-01-660ad310] INFO Core.PETaskScheduler - ** Completed PETaskCliEnforcement ** 2024-04-01 18:31:11,353 [RequestHandler-1-0x7f2883fff700 r=R0000003b-01-660ad310 h=581754 c=R0000003b-01-660ad310] INFO Core.PETaskScheduler - ** Completed PETaskPostAuthEnfProfileBuilder ** 2024-04-01 18:31:11,353 [RequestHandler-1-0x7f2883fff700 r=R0000003b-01-660ad310 h=581754 c=R0000003b-01-660ad310] INFO Core.PETaskScheduler - ** Completed PETaskRadiusCoAEnfProfileBuilder ** 2024-04-01 18:31:11,353 [RequestHandler-1-0x7f2883fff700 r=R0000003b-01-660ad310 h=581754 c=R0000003b-01-660ad310] INFO Core.PETaskScheduler - ** Starting PETaskAuthStatusInfo ** 2024-04-01 18:31:11,353 [RequestHandler-1-0x7f2883fff700 r=R0000003b-01-660ad310 h=581754 c=R0000003b-01-660ad310] INFO Core.PETaskScheduler - ** Starting PETaskOutputPolicyRes ** 2024-04-01 18:31:11,353 [RequestHandler-1-0x7f2883fff700 r=R0000003b-01-660ad310 h=581754 c=R0000003b-01-660ad310] INFO Core.PETaskScheduler - ** Starting PETaskSessionLog ** 2024-04-01 18:31:11,358 [RequestHandler-1-0x7f2883fff700 h=581768 c=R0000003b-01-660ad310] INFO Core.XpipPolicyResHandler - populateResponseTlv: PETaskPostureOutput does not exist. Skip sending posture VAFs 2024-04-01 18:31:11,358 [RequestHandler-1-0x7f2883fff700 h=581768 c=R0000003b-01-660ad310] INFO Core.PolicyResCollector - getSohr: Failed to generate Sohr 2024-04-01 18:31:11,358 [RequestHandler-1-0x7f2883fff700 h=581767 c=R0000003b-01-660ad310] INFO Core.PolicyResCollector - getSohr: Failed to generate Sohr 2024-04-01 18:31:11,358 [RequestHandler-1-0x7f2883fff700 r=R0000003b-01-660ad310 h=581754 c=R0000003b-01-660ad310] INFO Core.PETaskScheduler - ** Completed PETaskSessionLog ** 2024-04-01 18:31:11,359 [main SessId R0000003b-01-660ad310] DEBUG StatsDClient.StatsClient - Formatted StatsD data=default.cynac1.radius.policyeval.time:27|ms 2024-04-01 18:31:11,359 [main SessId R0000003b-01-660ad310] DEBUG StatsDClient.StatsClient - Sending StatsD request=default.cynac1.radius.policyeval.time:27|ms 2024-04-01 18:31:11,359 [main SessId R0000003b-01-660ad310] INFO RadiusServer.Radius - Policy Evaluation time = 27 ms 2024-04-01 18:31:11,359 [main SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_policy: policy_add_resp_attrs 2024-04-01 18:31:11,359 [main SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_policy: Processing HPE-CPPM-Role Attribute 2024-04-01 18:31:11,359 [main SessId R0000003b-01-660ad310] INFO RadiusServer.Radius - rlm_policy: Received Accept Enforcement Profile 2024-04-01 18:31:11,359 [main SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_policy: Request rejected. Not adding Class attribute. 2024-04-01 18:31:11,359 [main SessId R0000003b-01-660ad310] INFO RadiusServer.Radius - rlm_policy: Policy Server reply does not contain Posture-Validation-Response 2024-04-01 18:31:11,359 [main SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - Request Policy Evaluation Status: 1, Request Status: 3 2024-04-01 18:31:11,359 [main SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - adding alert message Client did not complete EAP transaction 2024-04-01 18:31:11,359 [main SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - rlm_policy: policy_release_polsvr_conn: Release Id: 0, handle: 0x1729a50 2024-04-01 18:31:11,359 [main SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcallpost-auth]: module "policy" returns reject for request 0 2024-04-01 18:31:11,359 [main SessId R0000003b-01-660ad310] DEBUG RadiusServer.Radius - modcall: leaving group REJECT (returns reject) for request 0 2024-04-01 18:31:11,359 [RequestHandler-1-0x7f2883fff700 r=R0000003b-01-660ad310 h=581754 c=R0000003b-01-660ad310] INFO Core.PETaskScheduler - ** Completed PETaskOutputPolicyRes ** 2024-04-01 18:31:11,359 [RequestHandler-1-0x7f2883fff700 r=R0000003b-01-660ad310 h=581754 c=R0000003b-01-660ad310] INFO Core.PETaskScheduler - ** Completed PETaskAuthStatusInfo ** 2024-04-01 18:31:11,359 [RequestHandler-1-0x7f2883fff700 r=R0000003b-01-660ad310 h=581754 c=R0000003b-01-660ad310] INFO Core.PETaskScheduler - *** PE_TASK_SCHEDULE_RADIUS Completed ***