log MX правда вставляется плохо
Nov 17 17:31:24.596 authd_serv_listen: Got a new client tcp = no
Nov 17 17:31:24.596 authd_serv_conn_new: accepted a new connection
Nov 17 17:31:24.615 authd_read_msg: Fresh msg arrival. fd=65, hdr_read=0, hdr_re mnant=0, payload_read=0 payload_remnant=0
Nov 17 17:31:24.615 fresh message conn=0x377f000
Nov 17 17:31:24.615 read fresh message conn=0x377f000 hdr_remnant=0 hdr_read=32
Nov 17 17:31:24.615 Read payload for new message. fd=65, rqst_len=50
Nov 17 17:31:24.615 Read payload for new message. fd=65, payload_len=18, rqst_le n=50, cookie=1
Nov 17 17:31:24.615 Process/Dispatch Client Message
Nov 17 17:31:24.615 New Process/Dispatch Client Message
Nov 17 17:31:24.615 authd_register_aaa_msg_create: num_of_tlvs:1
Nov 17 17:31:24.615 authd_conn_extract_conn_idRegister conn-id authdtest76102
Nov 17 17:31:24.615 authd_auth_force_add_conn:Authd forcely add conn 0x377f000, conn->fd is 65, conn->need_byteswap is no
Nov 17 17:31:24.615 authd_conn_extract_conn_id tunnel support false
Nov 17 17:31:24.615 authd_auth_send_answer: conn=377f000, reply-code=1 (OK), res ult-subopcode=25 (CLIENT_REGISTER_ACK), session-id:0, cookie=1, rply_len=28, num _tlv_blocks=0
Nov 17 17:31:24.616 authd_auth_aaa_msg_destroy
Nov 17 17:31:24.616 authd_auth_get_conn: Bad connection ID .
Nov 17 17:31:24.616 authd_auth_aaa_msg_destructauth_aaa_msg: 0x1f850b0
Nov 17 17:31:24.616 authd_write_conn: response is 0x377f05c, total len is 28 and sent is 0
Nov 17 17:31:24.616 authd_write_conn: response is 0x377f05c, wrote 28 bytes
Nov 17 17:31:24.616 authd_read_msg: Fresh msg arrival. fd=65, hdr_read=0, hdr_re mnant=0, payload_read=0 payload_remnant=0
Nov 17 17:31:24.616 fresh message conn=0x377f000
Nov 17 17:31:24.616 read fresh message conn=0x377f000 hdr_remnant=0 hdr_read=32
Nov 17 17:31:24.617 Read payload for new message. fd=65, rqst_len=70
Nov 17 17:31:24.617 Read payload for new message. fd=65, payload_len=38, rqst_le n=70, cookie=2
Nov 17 17:31:24.617 Process/Dispatch Client Message
Nov 17 17:31:24.617 New Process/Dispatch Client Message
Nov 17 17:31:24.617 authd_auth_aaa_msg_create: num_of_tlvs:4 tot_num_of_tlv:4
Nov 17 17:31:24.617 authd_auth_aaa_msg_create: profile:()
Nov 17 17:31:24.617 Process Request
Nov 17 17:31:24.617 Client request received on conn-id:authdtest76102 session-id :0 Opcode:2, Subcode:14
Nov 17 17:31:24.617 Decoding incoming attributes
Nov 17 17:31:24.617 Subscriber attribute 18, length 7
Nov 17 17:31:24.617 Subscriber attribute 39, length 7
Nov 17 17:31:24.617 Subscriber attribute 10007, length 4
Nov 17 17:31:24.617 Subscriber attribute 10007, length 4
Nov 17 17:31:24.617 Processing client update from client authdtest76102
Nov 17 17:31:24.617 Creating client authdtest76102
Nov 17 17:31:24.617 Adding rule External-Authority
Nov 17 17:31:24.617 Adding rule Network-Match
Nov 17 17:31:24.617 Clearing rule list
Nov 17 17:31:24.617 Adding rule External-Authority
Nov 17 17:31:24.617 Adding rule Network-Match
Nov 17 17:31:24.617 Adding rule External-Authority
Nov 17 17:31:24.617 Adding rule Network-Match
Nov 17 17:31:24.617 Sending message with opcode=0, result=2
Nov 17 17:31:24.617 authd_auth_send_answer: conn=377f000, reply-code=1 (OK), res ult-subopcode=1 (ACCESS_OK), session-id:0, cookie=2, rply_len=28, num_tlv_blocks =0
Nov 17 17:31:24.618 authd_auth_aaa_msg_destroy
Nov 17 17:31:24.618 authd_auth_aaa_msg_destructauth_aaa_msg: 0x1f850b0
Nov 17 17:31:24.618 authd_write_conn: response is 0x377f05c, total len is 28 and sent is 0
Nov 17 17:31:24.618 authd_write_conn: response is 0x377f05c, wrote 28 bytes
Nov 17 17:31:24.618 authd_read_msg: Fresh msg arrival. fd=65, hdr_read=0, hdr_re mnant=0, payload_read=0 payload_remnant=0
Nov 17 17:31:24.618 fresh message conn=0x377f000
Nov 17 17:31:24.618 read fresh message conn=0x377f000 hdr_remnant=0 hdr_read=32
Nov 17 17:31:24.618 Read payload for new message. fd=65, rqst_len=59
Nov 17 17:31:24.618 Read payload for new message. fd=65, payload_len=27, rqst_le n=59, cookie=3
Nov 17 17:31:24.618 Process/Dispatch Client Message
Nov 17 17:31:24.618 New Process/Dispatch Client Message
Nov 17 17:31:24.618 authd_tlv_build_list_from_struct username (0x20322d4) len:0
Nov 17 17:31:24.619 authd_tlv_build_list_from_struct profile (0x20321c4) len:0
Nov 17 17:31:24.619 authd_tlv_build_list_from_struct password (0x20320b4) len:0
Nov 17 17:31:24.619 authd_auth_aaa_msg_create: num_of_tlvs:0 tot_num_of_tlv:3
Nov 17 17:31:24.619 authd_auth_aaa_msg_create: profile:()
Nov 17 17:31:24.619 Process Request
Nov 17 17:31:24.619 Client request received on conn-id:authdtest76102 session-id :124 Opcode:3, Subcode:0
Nov 17 17:31:24.619 Taking client snapshot session-id:124
Nov 17 17:31:24.619 Creating SubscriberASTEntry for session-id:124, session name :14:88:77:34:78:83
Nov 17 17:31:24.619 UserAccess:14:88:77:34:78:83 session-id:124 state:login-requ est
Nov 17 17:31:24.619 initialize: No access-profile found in the SDB for session-i d:124
Nov 17 17:31:24.619 initialize: InterfaceName found in the SDB for session-id:12 4
Nov 17 17:31:24.619 Querying the access-profile for user:14:88:77:34:78:83 on LR /RI:default:default
Nov 17 17:31:24.619 Access Profile Name from context is <CLIENTS>
Nov 17 17:31:24.619 authd_get_auth_request_nas_attr: The request list is from aa a_msg
Nov 17 17:31:24.620 authd_get_auth_request_nas_attr: No Agent Circuit ID attribu te from SDB
Nov 17 17:31:24.620 authd_get_auth_request_nas_attr: No Agent Remote ID attribut e from SDB
Nov 17 17:31:24.620 authd_get_auth_request_nas_attr: No interface SVLAN attribut e from SDB
Nov 17 17:31:24.620 authd_get_auth_request_nas_attr: No interface VLAN attribute from SDB
Nov 17 17:31:24.620 authd_get_auth_request_nas_attr: No interface ATM VPI attrib ute from SDB
Nov 17 17:31:24.620 authd_get_auth_request_nas_attr: No interface ATM VCI attrib ute from SDB
Nov 17 17:31:24.620 authd_get_auth_request_nas_attr: Failed to get the NAS Port Type attribute from SDB
Nov 17 17:31:24.620 authd_get_auth_request_nas_attr: Recovered from SDB - SVlan: -1 Vlan:-1 NasPortType:0
Nov 17 17:31:24.620 authd_get_auth_request_nas_attr: Recovered from SDB - VPI:-1 VCI:-1 NasPortType:0
Nov 17 17:31:24.620 authd_get_auth_request_nas_attr: Failed to recover the under lying interface attribute from SDB
Nov 17 17:31:24.620 authd_build_radius_nas_port_and_id: NASPortID = -0/0/0.0, NA SPort = fff, CallingStationID =
Nov 17 17:31:24.621 Setting multi-acct-session-id to 0
Nov 17 17:31:24.621 setAccountingInfo: CLIENTS
Nov 17 17:31:24.621 setAccountingInfo: service accounting order
Nov 17 17:31:24.621 updateCoaDynamicVariableValidation coaValidation: 0
Nov 17 17:31:24.621 initialize JSRC: NOT calling jsrc restore function: - notify off - jsrc id empty
Nov 17 17:31:24.621 Bundle session id not found, setting to NULL
Nov 17 17:31:24.621 initialize: multi-acct-session-id set to 0
Nov 17 17:31:24.621 initialize: access profile: CLIENTS
Nov 17 17:31:24.621 On-demand IP address set to 0
Nov 17 17:31:24.621 UserAccess:14:88:77:34:78:83 session-id:124 Access-profile:C LIENTS Multi-Acct-Session-Id:0
Nov 17 17:31:24.621 authd_auth_modules_pre_feed_sanity: message passed sanity te st profile=(), username=()
Nov 17 17:31:24.621 AuthFsm::current state=AuthInit(0) event=1 astEntry=0x296650 0 aaa msg=0x1f850b0
Nov 17 17:31:24.621 ############################################################ #######
Nov 17 17:31:24.621 ########################### AUTH REQ RCVD ################## #######
Nov 17 17:31:24.621 ############################################################ #######
Nov 17 17:31:24.621 Auth-FSM: Process Auth-Request for session-id:124
Nov 17 17:31:24.621 Framework: Starting authentication
Nov 17 17:31:24.621 authd_advance_module_for_aaa_request_msg: result:0
Nov 17 17:31:24.621 Authd module start session-id:124
Nov 17 17:31:24.621 authd_radius_start_auth: Starting RADIUS authentication
Nov 17 17:31:24.621 authd_radius_build_basic_auth_request: got params profile=C LIENTS, username=14:88:77:34:78:83
Nov 17 17:31:24.622 radius-access-request: User-Name added: 14:88:77:34:78:83
Nov 17 17:31:24.622 radius-access-request: User-Password added: ""
Nov 17 17:31:24.622 radius-access-request: Service-Type added: 2
Nov 17 17:31:24.622 radius-access-request: Chargeable-User-Identity added:
Nov 17 17:31:24.622 radius-access-request: Acct-Session-Id added: 124
Nov 17 17:31:24.622 radius-access-request: DHCP-GI-Address (Juniper-ERX-VSA) add ed: 10.1.2.254
Nov 17 17:31:24.622 radius-access-request: DHCP-MAC-Address (Juniper-ERX-VSA) ad ded: abcd.0000.0001
Nov 17 17:31:24.622 radius-access-request: NAS-Identifier added: mx
Nov 17 17:31:24.622 radius-access-request: NAS-Port added: 00 00 0f ff
Nov 17 17:31:24.622 radius-access-request: NAS-Port-Id added: -0/0/0.0
Nov 17 17:31:24.622 radius-access-request: NAS-Port-Type added: 15
Nov 17 17:31:24.622 radius-access-request: PPPoE-Description (Juniper-ERX-VSA) a dded: pppoe ab:cd:00:00:00:01
Nov 17 17:31:24.622 authd_create_application_specific_radius_server: Evaluating RADIUS server 0xc0a800c9 to add to the server list
Nov 17 17:31:24.622 authd_radius_server_add: retry 3, timeout 3
Nov 17 17:31:24.623 authd_create_application_specific_radius_server: Evaluating RADIUS server 0xc0a80078 to add to the server list
Nov 17 17:31:24.623 authd_radius_server_add: retry 3, timeout 3
Nov 17 17:31:24.623 authd_create_application_specific_radius_server: Evaluating RADIUS server 0xc0a800b5 to add to the server list
Nov 17 17:31:24.623 Verify source address c0a8007a (192.168.0.122) in routing in stance index=0
Nov 17 17:31:24.623 authd_radius_server_add: retry 3, timeout 3
Nov 17 17:31:24.623 REQUEST: AUTHEN - module_index 0 module(radius) return: ASYN C
Nov 17 17:31:24.623 UserAccess:14:88:77:34:78:83 session-id:124 state:start -0/0 /0.0
Nov 17 17:31:24.623 Auth-FSM: GRES-Mirror for session-id:124 state:AuthStart(1)
Nov 17 17:32:00.646 authd_radius_get_config:Using radius option config from acce ss stanza
Nov 17 17:32:00.646 loadDefaultService:: default service for the subscriber is e mpty
Nov 17 17:32:00.646 Radius result is CLIENT_REQ_TIMEOUT
Nov 17 17:32:00.646 Framework - module(radius) return: SERVER
Nov 17 17:32:00.646 authd_advance_module_for_aaa_response_msg: result:4
Nov 17 17:32:00.647 authd_auth_update_local_server_address Searching access prof ile CLIENTS for local DNS Server
Nov 17 17:32:00.647 Auth-FSM: reinterpretFsmEvent 29 to 30
Nov 17 17:32:00.647 AuthFsm::current state=AuthStart(1) event=30 astEntry=0x2966 500 aaa msg=0x1f850b0
Nov 17 17:32:00.647 Auth-FSM: Post the Auth-Response and clean up. session-id:12 4
Nov 17 17:32:00.647 UserAccess:14:88:77:34:78:83 session-id:124 access-denied -0 /0/0.0
Nov 17 17:32:00.647 Framework: auth result is 12. Performing post-auth operation s
Nov 17 17:32:00.647 Framework: result is 12.
Nov 17 17:32:00.647 authd_auth_send_answer: conn=377f000, reply-code=3 (TIMEOUT) , result-subopcode=12 (ACCESS_TIMEOUT), session-id:124, cookie=3, rply_len=28, n um_tlv_blocks=0
Nov 17 17:32:00.647 Delete session-id:124
Nov 17 17:32:00.647 Begin to logout Subscriber session-id:
Nov 17 17:32:00.647 UserAccess:14:88:77:34:78:83 session-id:124 state:log-out -0 /0/0.0
Nov 17 17:32:00.647 Removing client snapshot session-id:124
Nov 17 17:32:00.647 authd_auth_aaa_msg_destroy
Nov 17 17:32:00.648 authd_auth_aaa_msg_destructauth_aaa_msg: 0x1f850b0
Nov 17 17:32:00.648 authd_write_conn: response is 0x377f05c, total len is 28 and sent is 0
Nov 17 17:32:00.648 authd_write_conn: response is 0x377f05c, wrote 28 bytes
Nov 17 17:32:04.600 authd_read_msg: Fresh msg arrival. fd=65, hdr_read=0, hdr_re mnant=0, payload_read=0 payload_remnant=0
Nov 17 17:32:04.600 fresh message conn=0x377f000
Nov 17 17:32:04.600 Reading remnants: premature EOF
Nov 17 17:32:04.600 authd_conn_terminate: Terminate connection 0x377f000
Nov 17 17:32:04.600 Reading remnants, errCode=2