FreeRadius2 issue when deployed as proxy for EAP-TLS
Hi,We are trying to setup a test bench to test the freeRadius in proxy mode for eap-TLS requests. We are seeing the host is sending request but the proxy is not seding the correct access request to home server. We are seeing from the logs that the proxy request to home server is treated as Authentication type basic instead of EAP-TLS. Regards,Muhammad Faisal. This message contains privileged and confidential information intended only for the use of the addressee named above. If you are not the intended recipient of this message, you must not disseminate, copy, or take any action in reliance on it.If you have received this message in error, please notify the sender immediately. No responsibility or liability is accepted by the writer, or any company associated with the writer, as to the accuracy of the information contained herein, or from any loss arising from reliance on it. Copyright and database rights exist in this document and to any attachment. Although we operate anti-virus programs, we do not accept responsibility for any damage whatsoever that is caused by viruses being passed.
On Tue, Apr 14, 2015 at 08:12:41AM +0000, Muhammad Faisal via Freeradius-Users wrote:
request to home server. We are seeing from the logs that the proxy request to home server is treated as Authentication type basic instead of EAP-TLS. Regards,Muhammad Faisal.
Debug logs? Matthew -- Matthew Newton, Ph.D. <mcn4@le.ac.uk> Systems Specialist, Infrastructure Services, I.T. Services, University of Leicester, Leicester LE1 7RH, United Kingdom For IT help contact helpdesk extn. 2253, <ithelp@le.ac.uk>
Hi Matthew,The dubug logs are pasted below for your kind review the issue seems " 14 Apr 2015 10:13:15,938 [ DEBUG ] AUTH-THR-8 [BASE AUTH DRIVER]: Request eligible for Basic authentication." due to which request is rejected by Home server: "Start of Logs:14 Apr 2015 10:11:02,872 [ DEBUG ] TimeBaseRollingTask [File Appender]: Count : 014 Apr 2015 10:13:00,950 [ INFO ] AUTH-LIS-THR [UDPService]: Packet Received by thread 014 Apr 2015 10:13:00,950 [ TRACE ] AUTH-THR-8 [UDPService]: Packet obtained from stream, assiging packet to the hanlder for processing.14 Apr 2015 10:13:00,950 [ DEBUG ] AUTH-THR-8 [UNIVERSAL ACCESS PLUGIN]: Applying Universal Access Policies to the request packet14 Apr 2015 10:13:00,950 [ DEBUG ] AUTH-THR-8 [UNIVERSAL PLUGIN POLICY MANAGER]: No Policy satisfied. Sending for normal processing14 Apr 2015 10:13:00,951 [ INFO ] AUTH-THR-8 [AUTH_STATUS]: Auth Request for Username="20107A2071EA@testbed.com" NAS-Identifier="HW-WASN" from 192.168.52.71/1814.9214 Apr 2015 10:13:00,951 [ INFO ] AUTH-THR-8 [AUTHENTICATION SERVICE]: Received ACCESS_REQUEST from 192.168.52.71:1814 with ID:92 and Length:247 User-Name = 20107A2071EA@testbed.com NAS-IP-Address = 192.168.52.75 Calling-Station-Id = 20107a2071ea NAS-Identifier = HW-WASN Event-Timestamp = 1428988035 EAP-Message = 0x020f001f01323031303741323037314541407175626565746573742e636f6d WiMAX WiMAX Capability Attribute = WiMAX Release = 0x312e31 Accounting Capabilities = 2 Hotlining Capabilities = 1 Idle Mode Notification Capabilities = 1 WiMAX WiMAX Capability Attribute = WiMAX Release = 0x15000060b52e0f003030303030373030313131301a0d0000 Framed-Interface-Id = 307:50:4600:3D 14 Apr 2015 10:13:00,951 [ INFO ] AUTH-THR-8 [AUTH PROXY SUB SERVICE]: No group selected as per specified realm. Sending for local processing.14 Apr 2015 10:13:00,951 [ INFO ] AUTH-THR-8 [AUTHENTICATION SERVICE]: No target system configured to forward the request.14 Apr 2015 10:13:00,951 [ TRACE ] AUTH-THR-8 [BASE DRIVER]: Base implementation of preProcess request invoked for com.elitecore.radius.commons.drivers.opendb.auth.OpenDBAuthDriver14 Apr 2015 10:13:00,951 [ DEBUG ] AUTH-THR-8 [BASE AUTH DRIVER]: Request eligible for Basic authentication.14 Apr 2015 10:13:00,951 [ DEBUG ] AUTH-THR-8 [OPEN DB AUTH DRIVER]: DataSource Name: opendb_ds_114 Apr 2015 10:13:00,951 [ DEBUG ] AUTH-THR-8 [OPEN DB AUTH DRIVER]: query=SELECT * FROM syn_vwradiuscustomer WHERE user_identity=?14 Apr 2015 10:13:01,862 [ DEBUG ] AUTH-THR-8 [OPEN DB AUTH DRIVER]: Query Execution Time : 91014 Apr 2015 10:13:01,862 [ DEBUG ] AUTH-THR-8 [BASE AUTH DRIVER]: User Profile: Username : 20107A2071EA@testbed.com Group Name : null CUI : null Passwd Check : Yes Encryption Type : null Customer Type : postpaid Service Type : null Calling Station Id : null Called Station Id : null Max Session Time : 0 Check Items : null Reject Items : null Reply Items : null Conc Login Policy : null Access Policy : null Radius Policy : Explore_1MB IP Pool Name : null Credit Limit : 1 Account Expiry Date : 2096-05-04 Account Status : Active Param1 : null Param2 : null Param3 : null Hotline Policy : null 14 Apr 2015 10:13:01,862 [ TRACE ] AUTH-THR-8 [BASE AUTH DRIVER]: ST KEY : [321] null14 Apr 2015 10:13:01,862 [ WARN ] AUTH-THR-8 [BASE AUTH DRIVER]: Unexpected problem matching password: null14 Apr 2015 10:13:01,862 [ INFO ] AUTH-THR-8 [BASE AUTH DRIVER]: Authentication failed. Reason: Invalid Password14 Apr 2015 10:13:01,862 [ TRACE ] AUTH-THR-8 [BASE AUTH DRIVER]: Invoked Post process implementation.14 Apr 2015 10:13:01,862 [ DEBUG ] AUTH-THR-8 [AUTHENTICATION SERVICE]: Request Context Response Attribute Map is empty 14 Apr 2015 10:13:01,862 [ INFO ] AUTH-THR-8 [AUTHENTICATION SERVICE]: Sending ACCESS_REJECT to 192.168.52.71:1814 ID:92 and Length:38 Reply-Message = Invalid Password 14 Apr 2015 10:13:01,862 [ INFO ] AUTH-THR-8 [UDPService]: Total response time : 912.466ms.14 Apr 2015 10:13:01,862 [ INFO ] AUTH-THR-8 [AUTH_STATUS]: Auth Response for Username="20107A2071EA@testbed.com" NAS-Identifier="HW-WASN" : ACCESS_REJECT [ REASON : Invalid Password ].14 Apr 2015 10:13:01,862 [ INFO ] AUTH-THR-8 [AUTH HELPER]: [ Authenticating User : 20107A2071EA@testbed.com ][ The status is : Invalid Password ]14 Apr 2015 10:13:01,863 [ DEBUG ] AUTH-THR-8 [UDPService]: Status of Removing Request from Duplicate Check Request Pool : true14 Apr 2015 10:13:15,937 [ INFO ] AUTH-LIS-THR [UDPService]: Packet Received by thread 014 Apr 2015 10:13:15,938 [ TRACE ] AUTH-THR-8 [UDPService]: Packet obtained from stream, assiging packet to the hanlder for processing.14 Apr 2015 10:13:15,938 [ DEBUG ] AUTH-THR-8 [UNIVERSAL ACCESS PLUGIN]: Applying Universal Access Policies to the request packet14 Apr 2015 10:13:15,938 [ DEBUG ] AUTH-THR-8 [UNIVERSAL PLUGIN POLICY MANAGER]: No Policy satisfied. Sending for normal processing14 Apr 2015 10:13:15,938 [ INFO ] AUTH-THR-8 [AUTH_STATUS]: Auth Request for Username="20107A2071EA@testbed.com" NAS-Identifier="HW-WASN" from 192.168.52.71/1814.2414 Apr 2015 10:13:15,938 [ INFO ] AUTH-THR-8 [AUTHENTICATION SERVICE]: Received ACCESS_REQUEST from 192.168.52.71:1814 with ID:24 and Length:246 User-Name = 20107A2071EA@testbed.com NAS-IP-Address = 192.168.52.75 Calling-Station-Id = 20107a2071ea NAS-Identifier = HW-WASN Event-Timestamp = 1428988050 EAP-Message = 0x020f001f01323031303741323037314541407175626565746573742e636f6d WiMAX WiMAX Capability Attribute = WiMAX Release = 0x312e31 Accounting Capabilities = 2 Hotlining Capabilities = 1 Idle Mode Notification Capabilities = 1 WiMAX WiMAX Capability Attribute = WiMAX Release = 0x15000060b52e0f003030303030373030313131301a0d0000 Framed-Interface-Id = 307:50:4600:3D 14 Apr 2015 10:13:15,938 [ INFO ] AUTH-THR-8 [AUTH PROXY SUB SERVICE]: No group selected as per specified realm. Sending for local processing.14 Apr 2015 10:13:15,938 [ INFO ] AUTH-THR-8 [AUTHENTICATION SERVICE]: No target system configured to forward the request.14 Apr 2015 10:13:15,938 [ TRACE ] AUTH-THR-8 [BASE DRIVER]: Base implementation of preProcess request invoked for com.elitecore.radius.commons.drivers.opendb.auth.OpenDBAuthDriver14 Apr 2015 10:13:15,938 [ DEBUG ] AUTH-THR-8 [BASE AUTH DRIVER]: Request eligible for Basic authentication.14 Apr 2015 10:13:15,938 [ DEBUG ] AUTH-THR-8 [OPEN DB AUTH DRIVER]: DataSource Name: opendb_ds_114 Apr 2015 10:13:15,938 [ DEBUG ] AUTH-THR-8 [OPEN DB AUTH DRIVER]: query=SELECT * FROM syn_vwradiuscustomer WHERE user_identity=?14 Apr 2015 10:13:15,940 [ DEBUG ] AUTH-THR-8 [OPEN DB AUTH DRIVER]: Query Execution Time : 114 Apr 2015 10:13:15,940 [ DEBUG ] AUTH-THR-8 [BASE AUTH DRIVER]: User Profile: Username : 20107A2071EA@testbed.com Group Name : null CUI : null Passwd Check : Yes Encryption Type : null Customer Type : postpaid Service Type : null Calling Station Id : null Called Station Id : null Max Session Time : 0 Check Items : null Reject Items : null Reply Items : null Conc Login Policy : null Access Policy : null Radius Policy : Explore_1MB IP Pool Name : null Credit Limit : 1 Account Expiry Date : 2096-05-04 Account Status : Active Param1 : null Param2 : null Param3 : null Hotline Policy : null 14 Apr 2015 10:13:15,940 [ TRACE ] AUTH-THR-8 [BASE AUTH DRIVER]: ST KEY : [322] null14 Apr 2015 10:13:15,940 [ WARN ] AUTH-THR-8 [BASE AUTH DRIVER]: Unexpected problem matching password: null14 Apr 2015 10:13:15,940 [ INFO ] AUTH-THR-8 [BASE AUTH DRIVER]: Authentication failed. Reason: Invalid Password14 Apr 2015 10:13:15,940 [ TRACE ] AUTH-THR-8 [BASE AUTH DRIVER]: Invoked Post process implementation.14 Apr 2015 10:13:15,940 [ DEBUG ] AUTH-THR-8 [AUTHENTICATION SERVICE]: Request Context Response Attribute Map is empty 14 Apr 2015 10:13:15,940 [ INFO ] AUTH-THR-8 [AUTHENTICATION SERVICE]: Sending ACCESS_REJECT to 192.168.52.71:1814 ID:24 and Length:38 Reply-Message = Invalid Password 14 Apr 2015 11:15:25,900 [ INFO ] AUTH-LIS-THR [UDPService]: Packet Received by thread 014 Apr 2015 11:15:25,900 [ TRACE ] AUTH-THR-8 [UDPService]: Packet obtained from stream, assiging packet to the hanlder for processing.14 Apr 2015 11:15:25,900 [ DEBUG ] AUTH-THR-8 [UNIVERSAL ACCESS PLUGIN]: Applying Universal Access Policies to the request packet14 Apr 2015 11:15:25,900 [ DEBUG ] AUTH-THR-8 [UNIVERSAL PLUGIN POLICY MANAGER]: No Policy satisfied. Sending for normal processing14 Apr 2015 11:15:25,900 [ INFO ] AUTH-THR-8 [AUTH_STATUS]: Auth Request for Username="20107A2071EA@testbed.com" NAS-Identifier="HW-WASN" from 192.168.52.71/1814.21314 Apr 2015 11:15:25,901 [ INFO ] AUTH-THR-8 [AUTHENTICATION SERVICE]: Received ACCESS_REQUEST from 192.168.52.71:1814 with ID:213 and Length:246 User-Name = 20107A2071EA@testbed.com NAS-IP-Address = 192.168.52.75 Calling-Station-Id = 20107a2071ea NAS-Identifier = HW-WASN Event-Timestamp = 1428991780 EAP-Message = 0x02a6001f01323031303741323037314541407175626565746573742e636f6d WiMAX WiMAX Capability Attribute = WiMAX Release = 0x312e31 Accounting Capabilities = 2 Hotlining Capabilities = 1 Idle Mode Notification Capabilities = 1 WiMAX WiMAX Capability Attribute = WiMAX Release = 0x15000060b52e0f003030303030373030313131301a0d0000 Framed-Interface-Id = 307:50:4600:3D 14 Apr 2015 11:15:25,901 [ INFO ] AUTH-THR-8 [AUTH PROXY SUB SERVICE]: No group selected as per specified realm. Sending for local processing.14 Apr 2015 11:15:25,901 [ INFO ] AUTH-THR-8 [AUTHENTICATION SERVICE]: No target system configured to forward the request.14 Apr 2015 11:15:25,901 [ TRACE ] AUTH-THR-8 [BASE DRIVER]: Base implementation of preProcess request invoked for com.elitecore.radius.commons.drivers.opendb.auth.OpenDBAuthDriver14 Apr 2015 11:15:25,901 [ DEBUG ] AUTH-THR-8 [BASE AUTH DRIVER]: Request eligible for Basic authentication.14 Apr 2015 11:15:25,901 [ DEBUG ] AUTH-THR-8 [OPEN DB AUTH DRIVER]: DataSource Name: opendb_ds_114 Apr 2015 11:15:25,901 [ DEBUG ] AUTH-THR-8 [OPEN DB AUTH DRIVER]: query=SELECT * FROM syn_vwradiuscustomer WHERE user_identity=?14 Apr 2015 11:15:25,903 [ DEBUG ] AUTH-THR-8 [OPEN DB AUTH DRIVER]: Query Execution Time : 114 Apr 2015 11:15:25,903 [ DEBUG ] AUTH-THR-8 [BASE AUTH DRIVER]: User Profile: Username : 20107A2071EA@testbed.com Group Name : null CUI : null Passwd Check : Yes Encryption Type : null Customer Type : postpaid Service Type : null Calling Station Id : null Called Station Id : null Max Session Time : 0 Check Items : null Reject Items : null Reply Items : null Conc Login Policy : null Access Policy : null Radius Policy : Explore_1MB IP Pool Name : null Credit Limit : 1 Account Expiry Date : 2096-05-04 Account Status : Active Param1 : null Param2 : null Param3 : null Hotline Policy : null 14 Apr 2015 11:15:25,903 [ TRACE ] AUTH-THR-8 [BASE AUTH DRIVER]: ST KEY : [323] null14 Apr 2015 11:15:25,903 [ WARN ] AUTH-THR-8 [BASE AUTH DRIVER]: Unexpected problem matching password: null14 Apr 2015 11:15:25,903 [ INFO ] AUTH-THR-8 [BASE AUTH DRIVER]: Authentication failed. Reason: Invalid Password14 Apr 2015 11:15:25,903 [ TRACE ] AUTH-THR-8 [BASE AUTH DRIVER]: Invoked Post process implementation.14 Apr 2015 11:15:25,903 [ DEBUG ] AUTH-THR-8 [AUTHENTICATION SERVICE]: Request Context Response Attribute Map is empty 14 Apr 2015 11:15:25,904 [ INFO ] AUTH-THR-8 [AUTHENTICATION SERVICE]: Sending ACCESS_REJECT to 192.168.52.71:1814 ID:213 and Length:38 Reply-Message = Invalid Password 14 Apr 2015 11:15:25,904 [ INFO ] AUTH-THR-8 [UDPService]: Total response time : 3.833ms.14 Apr 2015 11:15:25,904 [ INFO ] AUTH-THR-8 [AUTH_STATUS]: Auth Response for Username="20107A2071EA@testbed.com" NAS-Identifier="HW-WASN" : ACCESS_REJECT [ REASON : Invalid Password ].14 Apr 2015 11:15:25,904 [ INFO ] AUTH-THR-8 [AUTH HELPER]: [ Authenticating User : 20107A2071EA@testbed.com ][ The status is : Invalid Password ]14 Apr 2015 11:15:25,904 [ DEBUG ] AUTH-THR-8 [UDPService]: Status of Removing Request from Duplicate Check Request Pool : true14 Apr 2015 11:15:35,963 [ INFO ] AUTH-LIS-THR [UDPService]: Packet Received by thread 014 Apr 2015 11:15:35,964 [ TRACE ] AUTH-THR-8 [UDPService]: Packet obtained from stream, assiging packet to the hanlder for processing.14 Apr 2015 11:15:35,964 [ DEBUG ] AUTH-THR-8 [UNIVERSAL ACCESS PLUGIN]: Applying Universal Access Policies to the request packet14 Apr 2015 11:15:35,964 [ DEBUG ] AUTH-THR-8 [UNIVERSAL PLUGIN POLICY MANAGER]: No Policy satisfied. Sending for normal processing14 Apr 2015 11:15:35,964 [ INFO ] AUTH-THR-8 [AUTH_STATUS]: Auth Request for Username="20107A2071EA@testbed.com" NAS-Identifier="HW-WASN" from 192.168.52.71/1814.7114 Apr 2015 11:15:35,964 [ INFO ] AUTH-THR-8 [AUTHENTICATION SERVICE]: Received ACCESS_REQUEST from 192.168.52.71:1814 with ID:71 and Length:247 User-Name = 20107A2071EA@testbed.com NAS-IP-Address = 192.168.52.75 Calling-Station-Id = 20107a2071ea NAS-Identifier = HW-WASN Event-Timestamp = 1428991790 EAP-Message = 0x02bd001f01323031303741323037314541407175626565746573742e636f6d WiMAX WiMAX Capability Attribute = WiMAX Release = 0x312e31 Accounting Capabilities = 2 Hotlining Capabilities = 1 Idle Mode Notification Capabilities = 1 WiMAX WiMAX Capability Attribute = WiMAX Release = 0x15000060b52e0f003030303030373030313131301a0d0000 Framed-Interface-Id = 307:50:4600:3D 14 Apr 2015 11:15:35,964 [ INFO ] AUTH-THR-8 [AUTH PROXY SUB SERVICE]: No group selected as per specified realm. Sending for local processing.14 Apr 2015 11:15:35,964 [ INFO ] AUTH-THR-8 [AUTHENTICATION SERVICE]: No target system configured to forward the request.14 Apr 2015 11:15:35,964 [ TRACE ] AUTH-THR-8 [BASE DRIVER]: Base implementation of preProcess request invoked for com.elitecore.radius.commons.drivers.opendb.auth.OpenDBAuthDriver14 Apr 2015 11:15:35,964 [ DEBUG ] AUTH-THR-8 [BASE AUTH DRIVER]: Request eligible for Basic authentication.14 Apr 2015 11:15:35,964 [ DEBUG ] AUTH-THR-8 [OPEN DB AUTH DRIVER]: DataSource Name: opendb_ds_114 Apr 2015 11:15:35,964 [ DEBUG ] AUTH-THR-8 [OPEN DB AUTH DRIVER]: query=SELECT * FROM syn_vwradiuscustomer WHERE user_identity=?14 Apr 2015 11:15:35,966 [ DEBUG ] AUTH-THR-8 [OPEN DB AUTH DRIVER]: Query Execution Time : 114 Apr 2015 11:15:35,966 [ DEBUG ] AUTH-THR-8 [BASE AUTH DRIVER]: User Profile: Username : 20107A2071EA@testbed.com Group Name : null CUI : null Passwd Check : Yes Encryption Type : null Customer Type : postpaid Service Type : null Calling Station Id : null Called Station Id : null Max Session Time : 0 Check Items : null Reject Items : null Reply Items : null Conc Login Policy : null Access Policy : null Radius Policy : Explore_1MB IP Pool Name : null Credit Limit : 1 Account Expiry Date : 2096-05-04 Account Status : Active Param1 : null Param2 : null Param3 : null Hotline Policy : null 14 Apr 2015 11:15:35,966 [ TRACE ] AUTH-THR-8 [BASE AUTH DRIVER]: ST KEY : [324] null14 Apr 2015 11:15:35,966 [ WARN ] AUTH-THR-8 [BASE AUTH DRIVER]: Unexpected problem matching password: null14 Apr 2015 11:15:35,966 [ INFO ] AUTH-THR-8 [BASE AUTH DRIVER]: Authentication failed. Reason: Invalid Password14 Apr 2015 11:15:35,966 [ TRACE ] AUTH-THR-8 [BASE AUTH DRIVER]: Invoked Post process implementation.14 Apr 2015 11:15:35,966 [ DEBUG ] AUTH-THR-8 [AUTHENTICATION SERVICE]: Request Context Response Attribute Map is empty 14 Apr 2015 11:15:35,967 [ INFO ] AUTH-THR-8 [AUTHENTICATION SERVICE]: Sending ACCESS_REJECT to 192.168.52.71:1814 ID:71 and Length:38 Reply-Message = Invalid Password 14 Apr 2015 11:15:35,967 [ INFO ] AUTH-THR-8 [UDPService]: Total response time : 3.267ms.14 Apr 2015 11:15:35,967 [ INFO ] AUTH-THR-8 [AUTH_STATUS]: Auth Response for Username="20107A2071EA@testbed.com" NAS-Identifier="HW-WASN" : ACCESS_REJECT [ REASON : Invalid Password ].14 Apr 2015 11:15:35,967 [ INFO ] AUTH-THR-8 [AUTH HELPER]: [ Authenticating User : 20107A2071EA@testbed.com ][ The status is : Invalid Password ]14 Apr 2015 11:15:35,967 [ DEBUG ] AUTH-THR-8 [UDPService]: Status of Removing Request from Duplicate Check Request Pool : true14 Apr 2015 11:15:50,965 [ INFO ] AUTH-LIS-THR [UDPService]: Packet Received by thread 014 Apr 2015 11:15:50,966 [ TRACE ] AUTH-THR-8 [UDPService]: Packet obtained from stream, assiging packet to the hanlder for processing.14 Apr 2015 11:15:50,966 [ DEBUG ] AUTH-THR-8 [UNIVERSAL ACCESS PLUGIN]: Applying Universal Access Policies to the request packet14 Apr 2015 11:15:50,966 [ DEBUG ] AUTH-THR-8 [UNIVERSAL PLUGIN POLICY MANAGER]: No Policy satisfied. Sending for normal processing14 Apr 2015 11:15:50,966 [ INFO ] AUTH-THR-8 [AUTH_STATUS]: Auth Request for Username="20107A2071EA@testbed.com" NAS-Identifier="HW-WASN" from 192.168.52.71/1814.15514 Apr 2015 11:15:50,966 [ INFO ] AUTH-THR-8 [AUTHENTICATION SERVICE]: Received ACCESS_REQUEST from 192.168.52.71:1814 with ID:155 and Length:246 User-Name = 20107A2071EA@testbed.com NAS-IP-Address = 192.168.52.75 Calling-Station-Id = 20107a2071ea NAS-Identifier = HW-WASN Event-Timestamp = 1428991805 EAP-Message = 0x02a7001f01323031303741323037314541407175626565746573742e636f6d WiMAX WiMAX Capability Attribute = WiMAX Release = 0x312e31 Accounting Capabilities = 2 Hotlining Capabilities = 1 Idle Mode Notification Capabilities = 1 WiMAX WiMAX Capability Attribute = WiMAX Release = 0x15000060b52e0f003030303030373030313131301a0d0000 Framed-Interface-Id = 307:50:4600:3D 14 Apr 2015 11:15:50,966 [ INFO ] AUTH-THR-8 [AUTH PROXY SUB SERVICE]: No group selected as per specified realm. Sending for local processing.14 Apr 2015 11:15:50,966 [ INFO ] AUTH-THR-8 [AUTHENTICATION SERVICE]: No target system configured to forward the request.14 Apr 2015 11:15:50,966 [ TRACE ] AUTH-THR-8 [BASE DRIVER]: Base implementation of preProcess request invoked for com.elitecore.radius.commons.drivers.opendb.auth.OpenDBAuthDriver14 Apr 2015 11:15:50,966 [ DEBUG ] AUTH-THR-8 [BASE AUTH DRIVER]: Request eligible for Basic authentication.14 Apr 2015 11:15:50,966 [ DEBUG ] AUTH-THR-8 [OPEN DB AUTH DRIVER]: DataSource Name: opendb_ds_114 Apr 2015 11:15:50,966 [ DEBUG ] AUTH-THR-8 [OPEN DB AUTH DRIVER]: query=SELECT * FROM syn_vwradiuscustomer WHERE user_identity=?14 Apr 2015 11:15:50,968 [ DEBUG ] AUTH-THR-8 [OPEN DB AUTH DRIVER]: Query Execution Time : 114 Apr 2015 11:15:50,968 [ DEBUG ] AUTH-THR-8 [BASE AUTH DRIVER]: User Profile: Username : 20107A2071EA@testbed.com Group Name : null CUI : null Passwd Check : Yes Encryption Type : null Customer Type : postpaid Service Type : null Calling Station Id : null Called Station Id : null Max Session Time : 0 Check Items : null Reject Items : null Reply Items : null Conc Login Policy : null Access Policy : null Radius Policy : Explore_1MB IP Pool Name : null Credit Limit : 1 Account Expiry Date : 2096-05-04 Account Status : Active Param1 : null Param2 : null Param3 : null Hotline Policy : null 14 Apr 2015 11:15:50,968 [ TRACE ] AUTH-THR-8 [BASE AUTH DRIVER]: ST KEY : [325] null14 Apr 2015 11:15:50,968 [ WARN ] AUTH-THR-8 [BASE AUTH DRIVER]: Unexpected problem matching password: null14 Apr 2015 11:15:50,968 [ INFO ] AUTH-THR-8 [BASE AUTH DRIVER]: Authentication failed. Reason: Invalid Password14 Apr 2015 11:15:50,969 [ TRACE ] AUTH-THR-8 [BASE AUTH DRIVER]: Invoked Post process implementation.14 Apr 2015 11:15:50,969 [ DEBUG ] AUTH-THR-8 [AUTHENTICATION SERVICE]: Request Context Response Attribute Map is empty 14 Apr 2015 11:15:50,969 [ INFO ] AUTH-THR-8 [AUTHENTICATION SERVICE]: Sending ACCESS_REJECT to 192.168.52.71:1814 ID:155 and Length:38 Reply-Message = Invalid Password 14 Apr 2015 11:15:50,969 [ INFO ] AUTH-THR-8 [UDPService]: Total response time : 3.117ms.14 Apr 2015 11:15:50,969 [ INFO ] AUTH-THR-8 [AUTH_STATUS]: Auth Response for Username="20107A2071EA@testbed.com" NAS-Identifier="HW-WASN" : ACCESS_REJECT [ REASON : Invalid Password ].14 Apr 2015 11:15:50,969 [ INFO ] AUTH-THR-8 [AUTH HELPER]: [ Authenticating User : 20107A2071EA@testbed.com ][ The status is : Invalid Password ]14 Apr 2015 11:15:50,969 [ DEBUG ] AUTH-THR-8 [UDPService]: Status of Removing Request from Duplicate Check Request Pool : true14 Apr 2015 11:16:00,913 [ INFO ] AUTH-LIS-THR [UDPService]: Packet Received by thread 014 Apr 2015 11:16:00,913 [ TRACE ] AUTH-THR-8 [UDPService]: Packet obtained from stream, assiging packet to the hanlder for processing.14 Apr 2015 11:16:00,913 [ DEBUG ] AUTH-THR-8 [UNIVERSAL ACCESS PLUGIN]: Applying Universal Access Policies to the request packet14 Apr 2015 11:16:00,913 [ DEBUG ] AUTH-THR-8 [UNIVERSAL PLUGIN POLICY MANAGER]: No Policy satisfied. Sending for normal processing14 Apr 2015 11:16:00,913 [ INFO ] AUTH-THR-8 [AUTH_STATUS]: Auth Request for Username="20107A2071EA@testbed.com" NAS-Identifier="HW-WASN" from 192.168.52.71/1814.7714 Apr 2015 11:16:00,913 [ INFO ] AUTH-THR-8 [AUTHENTICATION SERVICE]: Received ACCESS_REQUEST from 192.168.52.71:1814 with ID:77 and Length:247 User-Name = 20107A2071EA@testbed.com NAS-IP-Address = 192.168.52.75 Calling-Station-Id = 20107a2071ea NAS-Identifier = HW-WASN Event-Timestamp = 1428991815 EAP-Message = 0x02c0001f01323031303741323037314541407175626565746573742e636f6d WiMAX WiMAX Capability Attribute = WiMAX Release = 0x312e31 Accounting Capabilities = 2 Hotlining Capabilities = 1 Idle Mode Notification Capabilities = 1 WiMAX WiMAX Capability Attribute = WiMAX Release = 0x15000060b52e0f003030303030373030313131301a0d0000 Framed-Interface-Id = 307:50:4600:3D 14 Apr 2015 11:16:00,914 [ INFO ] AUTH-THR-8 [AUTH PROXY SUB SERVICE]: No group selected as per specified realm. Sending for local processing.14 Apr 2015 11:16:00,914 [ INFO ] AUTH-THR-8 [AUTHENTICATION SERVICE]: No target system configured to forward the request.14 Apr 2015 11:16:00,914 [ TRACE ] AUTH-THR-8 [BASE DRIVER]: Base implementation of preProcess request invoked for com.elitecore.radius.commons.drivers.opendb.auth.OpenDBAuthDriver14 Apr 2015 11:16:00,914 [ DEBUG ] AUTH-THR-8 [BASE AUTH DRIVER]: Request eligible for Basic authentication.14 Apr 2015 11:16:00,914 [ DEBUG ] AUTH-THR-8 [OPEN DB AUTH DRIVER]: DataSource Name: opendb_ds_114 Apr 2015 11:16:00,914 [ DEBUG ] AUTH-THR-8 [OPEN DB AUTH DRIVER]: query=SELECT * FROM syn_vwradiuscustomer WHERE user_identity=?14 Apr 2015 11:16:00,915 [ DEBUG ] AUTH-THR-8 [OPEN DB AUTH DRIVER]: Query Execution Time : 114 Apr 2015 11:16:00,916 [ DEBUG ] AUTH-THR-8 [BASE AUTH DRIVER]: User Profile: Username : 20107A2071EA@testbed.com Group Name : null CUI : null Passwd Check : Yes Encryption Type : null Customer Type : postpaid Service Type : null Calling Station Id : null Called Station Id : null Max Session Time : 0 Check Items : null Reject Items : null Reply Items : null Conc Login Policy : null Access Policy : null Radius Policy : Explore_1MB IP Pool Name : null Credit Limit : 1 Account Expiry Date : 2096-05-04 Account Status : Active Param1 : null Param2 : null Param3 : null Hotline Policy : null 14 Apr 2015 11:16:00,916 [ TRACE ] AUTH-THR-8 [BASE AUTH DRIVER]: ST KEY : [326] null14 Apr 2015 11:16:00,916 [ WARN ] AUTH-THR-8 [BASE AUTH DRIVER]: Unexpected problem matching password: null14 Apr 2015 11:16:00,916 [ INFO ] AUTH-THR-8 [BASE AUTH DRIVER]: Authentication failed. Reason: Invalid Password14 Apr 2015 11:16:00,916 [ TRACE ] AUTH-THR-8 [BASE AUTH DRIVER]: Invoked Post process implementation.14 Apr 2015 11:16:00,916 [ DEBUG ] AUTH-THR-8 [AUTHENTICATION SERVICE]: Request Context Response Attribute Map is empty 14 Apr 2015 11:16:00,916 [ INFO ] AUTH-THR-8 [AUTHENTICATION SERVICE]: Sending ACCESS_REJECT to 192.168.52.71:1814 ID:77 and Length:38 Reply-Message = Invalid Password 14 Apr 2015 11:16:00,916 [ INFO ] AUTH-THR-8 [UDPService]: Total response time : 3.297ms.14 Apr 2015 11:16:00,916 [ INFO ] AUTH-THR-8 [AUTH_STATUS]: Auth Response for Username="20107A2071EA@testbed.com" NAS-Identifier="HW-WASN" : ACCESS_REJECT [ REASON : Invalid Password ].14 Apr 2015 11:16:00,916 [ INFO ] AUTH-THR-8 [AUTH HELPER]: [ Authenticating User : 20107A2071EA@testbed.com ][ The status is : Invalid Password ] End of Logs" Regards, Muhammad Faisal. From: Matthew Newton <mcn4@leicester.ac.uk> To: Muhammad Faisal <faisalusuf@yahoo.com>; FreeRadius users mailing list <freeradius-users@lists.freeradius.org> Sent: Tuesday, April 14, 2015 2:49 PM Subject: Re: FreeRadius2 issue when deployed as proxy for EAP-TLS On Tue, Apr 14, 2015 at 08:12:41AM +0000, Muhammad Faisal via Freeradius-Users wrote:
request to home server. We are seeing from the logs that the proxy request to home server is treated as Authentication type basic instead of EAP-TLS. Regards,Muhammad Faisal.
Debug logs? Matthew -- Matthew Newton, Ph.D. <mcn4@le.ac.uk> Systems Specialist, Infrastructure Services, I.T. Services, University of Leicester, Leicester LE1 7RH, United Kingdom For IT help contact helpdesk extn. 2253, <ithelp@le.ac.uk>
On Apr 14, 2015, at 7:46 AM, Muhammad Faisal via Freeradius-Users <freeradius-users@lists.freeradius.org> wrote:
Hi Matthew,The dubug logs are pasted below for your kind review the issue seems "
Post the logs in a NORMAL format. You've mashed all of the lines together so that the output is unusable. Alan DeKok.
Hi, On Tue, Apr 14, 2015 at 11:46:59AM +0000, Muhammad Faisal wrote:
The dubug logs are pasted below for your kind review the issue seems " 14 Apr 2015 10:13:15,938 [ DEBUG ] AUTH-THR-8 [BASE AUTH DRIVER]: Request eligible for Basic authentication." due to which request is rejected by Home server:
Don't know what those logs are - maybe I should have been more clear. We need the debug output from the FreeRADIUS server that you get when running radiusd -X so we can see what FreeRADIUS is doing. This is the FreeRADIUS list... Having said that this log line indicates that an EAP-Message with EAP type EAP-TLS arrived. So whatever system this log comes from, I'm guessing EAP-TLS isn't configured properly. It doesn't look like a FreeRADIUS issue. 14 Apr 2015 11:15:25,901 [ INFO ] AUTH-THR-8 [AUTHENTICATION SERVICE]: Received ACCESS_REQUEST from 192.168.52.71:1814 with ID:213 and Length:246 User-Name = 20107A2071EA@testbed.com NAS-IP-Address = 192.168.52.75 Calling-Station-Id = 20107a2071ea NAS-Identifier = HW-WASN Event-Timestamp = 1428991780 EAP-Message = 0x02a6001f01323031303741323037314541407175626565746573742e636f6d WiMAX WiMAX Capability Attribute = WiMAX Release = 0x312e31 Accounting Capabilities = 2 Hotlining Capabilities = 1 Idle Mode Notification Capabilities = 1 WiMAX WiMAX Capability Attribute = WiMAX Release = 0x15000060b52e0f003030303030373030313131301a0d0000 Framed-Interface-Id = 307:50:4600:3D Please send plain text messages to the list not HTML. Whatever you sent was really mangled up. Matthew -- Matthew Newton, Ph.D. <mcn4@le.ac.uk> Systems Specialist, Infrastructure Services, I.T. Services, University of Leicester, Leicester LE1 7RH, United Kingdom For IT help contact helpdesk extn. 2253, <ithelp@le.ac.uk>
participants (3)
-
Alan DeKok -
Matthew Newton -
Muhammad Faisal