Dear Friends,
My Linux Free radius Server is continuously rejecting login authentication from my IPoE subscribers. These are the IPoE authentication logs:
root@IPOE# run show log authlog | last 200
Jan 31 10:10:29.961075 access profile: local
Jan 31 10:10:29.961086 On-demand IP address set to 0
Jan 31 10:10:29.961102 authd_auth_modules_pre_feed_sanity: message passed sanity test profile=(), username=()
Jan 31 10:10:29.961124 AuthFsm::current state=AuthInit(0) event=1 astEntry=0x98a806c aaa msg=0x992306c session-id:20739
Jan 31 10:10:29.961139 ###################################################################
Jan 31 10:10:29.961147 ########################### AUTH REQ RCVD #########################
Jan 31 10:10:29.961159 ###################################################################
Jan 31 10:10:29.961175 Auth-FSM: Process Auth-Request for session-id:20739 username <5002.0010.0000> profile <local>
Jan 31 10:10:29.961195 Framework: Starting authentication
Jan 31 10:10:29.961213 authd_advance_module_for_aaa_request_msg: result:0
Jan 31 10:10:29.961235 Authd module start session-id:20739
Jan 31 10:10:29.961250 authd_radius_start_auth: Starting RADIUS authentication session-id:20739
Jan 31 10:10:29.961321 authd_radius_build_basic_auth_request: session-id:20739 profile=local, username=5002.0010.0000
Jan 31 10:10:29.961349 radius-access-request: User-Name added: 5002.0010.0000
Jan 31 10:10:29.961366 radius-access-request: User-Password added: ""
Jan 31 10:10:29.961407 radius-access-request: Service-Type added: 2
Jan 31 10:10:29.961443 radius-access-request: Chargeable-User-Identity added:
Jan 31 10:10:29.961459 radius-access-request: Acct-Session-Id added: 20739
Jan 31 10:10:29.961492 radius-access-request: DHCP-Options (Juniper-ERX-VSA) added: 35 01 01 37 08 01 79 03 21 06 2a 8a 2b 0c 0b 4d 43 52 2e 62 6f 78 2e 6c 61 62 3d 07 01 50 02 00 10 00 00
Jan 31 10:10:29.961511 radius-access-request: DHCP-MAC-Address (Juniper-ERX-VSA) added: 5002.0010.0000
Jan 31 10:10:29.961531 radius-access-request: NAS-Identifier added: IPOE
Jan 31 10:10:29.961545 radius-access-request: NAS-Port added: 00 80 0d 05
Jan 31 10:10:29.961556 radius-access-request: NAS-Port-Id added: ge-0/0/2.3221228447:3333
Jan 31 10:10:29.961569 radius-access-request: NAS-Port-Type added: 15
Jan 31 10:10:29.961587 radius-access-request: PPPoE-Description (Juniper-ERX-VSA) added: pppoe 50:02:00:10:00:00
Jan 31 10:10:29.961608 radius-access-request: DHCP-First-Relay-IPv4-Address (Juniper-ERX-VSA) added: 192.168.3.254
Jan 31 10:10:29.961648 radius-access-request: DHCP-Header (Juniper-ERX-VSA) added: 01 01 06 00 0a 3a 68 53 00 29 80 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 50 02 00 10 00 00 00 00 00 00 00 00 00 00 00 00
Jan 31 10:10:29.961679 authd_create_application_specific_radius_server: Evaluating RADIUS server 192.168.3.251 to add to the server list
Jan 31 10:10:29.961700 Evaluating RADIUS server 192.168.3.251 to add to the server list
Jan 31 10:10:29.961719 authd_radius_server_add: server 192.168.3.251 retry 3, timeout 3
Jan 31 10:10:29.961744 processSessionAttributeNasAddress 20739
Jan 31 10:10:29.961855 processSessionAttributeNasAddress return false
Jan 31 10:10:29.962045 Request queued successfully
Jan 31 10:10:29.962069 REQUEST: AUTHEN - module_index 0 module(radius) return: ASYNC
Jan 31 10:10:29.962086 Auth-FSM: GRES-Mirror for session-id:20739 state:AuthStart(1)
Jan 31 10:10:31.931546 RadiusServer: server[0] used for last request - 192.168.3.251
Jan 31 10:10:31.931619 authd_radius_callback: RADIUS server sent an ACCESS_REJECT, failing login for session-id:20739
Jan 31 10:10:31.931961 loadDefaultService:: default service for the subscriber is empty
Jan 31 10:10:31.931976 Radius result is CLIENT_REQ_STATUS_SUCCESS
Jan 31 10:10:31.931996 Parsing RADIUS message for session-id:20739
Jan 31 10:10:31.932017 Framework - module(radius) return: FAILURE
Jan 31 10:10:31.932028 authd_advance_module_for_aaa_response_msg: result:3
Jan 31 10:10:31.932078 Finding a client snapshot session-id:20739
Jan 31 10:10:31.932109 AuthFsm::current state=AuthStart(1) event=4 astEntry=0x98a806c aaa msg=0x992306c session-id:20739
Jan 31 10:10:31.932125 Auth-FSM: Post the Auth-Response and clean up. session-id:20739
Jan 31 10:10:31.932137 Setting terminate ID to 30001
Jan 31 10:10:31.932169 Only start time found for session-id:20739
Jan 31 10:10:31.932183 Framework: auth result is 9. Performing post-auth operations
Jan 31 10:10:31.932193 Framework: result is 9.
Jan 31 10:10:31.932208 SEQ SendClientMsg:jdhcpd-client session-id:20739 reply-code=2 (FAIL), result-subopcode=9 (ACCESS_DENY), cookie=83299, rply_len=4480, num_tlv_blocks=0
Jan 31 10:10:31.932229 authd_auth_aaa_msg_destruct auth_aaa_msg: 0x99235dc
Jan 31 10:10:31.932248 Delete session-id:20739
Jan 31 10:10:31.932259 Begin to logout Subscriber
Jan 31 10:10:31.932272 subscriberLogout session-id:20739
Jan 31 10:10:36.022904 Process/Dispatch Client Message
Jan 31 10:10:36.022949 New Process/Dispatch Client Message
Jan 31 10:10:36.022971 authd_tlv_build_list_from_struct username l =1 offset =56
Jan 31 10:10:36.022983 authd_tlv_build_list_from_struct profile l =1 offset =57
Jan 31 10:10:36.022994 authd_tlv_build_list_from_struct password l =1 offset =58
Jan 31 10:10:36.023005 authd_auth_aaa_msg_create: num_of_tlvs:0 tot_num_of_tlv:0
Jan 31 10:10:36.023017 authd_auth_aaa_msg_create username:() profile:()
Jan 31 10:10:36.023029 Process Request
Jan 31 10:10:36.023042 SEQ RecvClientMsg:jdhcpd-client session-id:20740 Opcode:65, Subcode:0 (ACCESS_REQUEST)
Jan 31 10:10:36.023059 Taking a client snapshot, session-id:20740
Jan 31 10:10:36.023091 getSubscriberAaaOptionsName
Jan 31 10:10:36.023111 authd_build_req_attr_list_from_sdb_data: The request list is from sdb
Jan 31 10:10:36.023144 createSubscriberSession UserName (5002.0010.0000) for session-id:20740 from SDB
Jan 31 10:10:36.023181 Creating SubscriberASTEntry for session-id:20740, session name:5002.0010.0000
Jan 31 10:10:36.023208 fillSessionDBAttributes: session-id:20740, ifdName: ge-0/0/2
Jan 31 10:10:36.023228 No access-profile found in the SDB for session-id:20740
Jan 31 10:10:36.023241 Bbe Domain Id found in the SDB for session-id:20740
Jan 31 10:10:36.023254 PhyIfdName found in the SDB for session-id:20740
Jan 31 10:10:36.023274 aaa ls:default aaa ri:default; target ls:default target ri: default
Jan 31 10:10:36.023289 setTargetRoutingContextdefault:default
Jan 31 10:10:36.023302 Querying the access-profile for user:5002.0010.0000 on LR/RI:default:default
Jan 31 10:10:36.023314 Access Profile Name from context is <local>
Jan 31 10:10:36.023335 authd_build_radius_nas_port_and_id: nas-port-id-format order is disabled
Jan 31 10:10:36.023347 authd_build_req_attr_list_from_sdb_data: The request list is from aaa_msg
Jan 31 10:10:36.023366 authd_get_auth_request_nas_attr: No Agent Circuit ID attribute from SDB
Jan 31 10:10:36.023377 authd_get_auth_request_nas_attr: No Agent Remote ID attribute from SDB
Jan 31 10:10:36.023388 authd_get_auth_request_nas_attr: No interface SVLAN attribute from SDB
Jan 31 10:10:36.023399 authd_get_auth_request_nas_attr: No interface ATM VPI attribute from SDB
Jan 31 10:10:36.023410 authd_get_auth_request_nas_attr: No interface ATM VCI attribute from SDB
Jan 31 10:10:36.023420 authd_get_auth_request_nas_attr: Recovered from SDB - VPI:-1 VCI:-1 NasPortType:15
----------------------------------------------------------------------------------------------------------------------
Although I have subscriber with MAC Address as username however, no IP yet.
My Radius Server Logs is like that:
My Access configuration is below:
root@IPOE# show access
radius-server {
192.168.3.251 {
port 1812;
accounting-port 1813;
secret "$9$lz5vMLaJDjqfZUqfzFtpLxN"; ## SECRET-DATA
timeout 10;
retry 3;
max-outstanding-requests 2000;
source-address 192.168.3.200;
}
}
profile local {
authentication-order radius;
radius {
authentication-server 192.168.3.251;
accounting-server 192.168.3.251;
options {
accounting-session-id-format description;
client-authentication-algorithm direct;
}
}
radius-server {
192.168.3.251 {
port 1812;
accounting-port 1813;
dynamic-request-port 3799;
secret "$9$jHkqPu0IRSeoJi.5T9CM8X"; ## SECRET-DATA
}
}
}
address-assignment {
pool dhcp-ipoe {
family inet {
network 192.168.3.0/24;
range 1 {
low 192.168.3.11;
high 192.168.3.20;
}
dhcp-attributes {
maximum-lease-time 3600;
domain-name box.lab;
router {
192.168.3.254;
}
}
}
}
}
------------------------------
Nazmus Sakib
------------------------------