ip address allocated but soon released
Hi! I wanna freeradius2 as a dhcp-server When I connect to freeradius-server from laptop (Windows Vista) via ERX310 by using PPPoE Following massages appeared. On the laptop I saw an error message "*Error 734: The PPP link control protocol was terminated."* What's wrong with my configuration? Please suggest to me what information should I provide you. ---------------------------raius.log---------------------------------- Mon Apr 28 01:05:03 2014 : Info: ... adding new socket proxy address * port 36233 Mon Apr 28 01:05:03 2014 : Info: Ready to process requests. Mon Apr 28 01:06:11 2014 : Auth: Login OK: [user@mondomaine.fr] (from client GGSN1 port 369098752 cli #ERX-40-b0-7a#E16#0) Mon Apr 28 01:06:11 2014 : Info: Allocated IP: 192.168.0.1 from pool1 (did cli #ERX-40-b0-7a#E16#0 port 369098752 user user@mondomaine.fr) Mon Apr 28 01:06:18 2014 : Info: Released IP 192.168.0.1 (did cli #ERX-40-b0-7a#E16#0 user user@mondomaine.fr) Mon Apr 28 01:06:22 2014 : Info: Signalled to terminate Mon Apr 28 01:06:22 2014 : Info: Exiting normally. Mon Apr 28 01:06:22 2014 : Info: rlm_sql (sql): Closing sqlsocket 14 Mon Apr 28 01:06:22 2014 : Info: rlm_sql (sql): Closing sqlsocket 13 Mon Apr 28 01:06:22 2014 : Info: rlm_sql (sql): Closing sqlsocket 12 Mon Apr 28 01:06:22 2014 : Info: rlm_sql (sql): Closing sqlsocket 11 Mon Apr 28 01:06:22 2014 : Info: rlm_sql (sql): Closing sqlsocket 10 Mon Apr 28 01:06:22 2014 : Info: rlm_sql (sql): Closing sqlsocket 9 Mon Apr 28 01:06:22 2014 : Info: rlm_sql (sql): Closing sqlsocket 8 Mon Apr 28 01:06:22 2014 : Info: rlm_sql (sql): Closing sqlsocket 7 Mon Apr 28 01:06:22 2014 : Info: rlm_sql (sql): Closing sqlsocket 6 Mon Apr 28 01:06:22 2014 : Info: rlm_sql (sql): Closing sqlsocket 5 Mon Apr 28 01:06:22 2014 : Info: rlm_sql (sql): Closing sqlsocket 4 Mon Apr 28 01:06:22 2014 : Info: rlm_sql (sql): Closing sqlsocket 3 Mon Apr 28 01:06:22 2014 : Info: rlm_sql (sql): Closing sqlsocket 2 Mon Apr 28 01:06:22 2014 : Info: rlm_sql (sql): Closing sqlsocket 1 Mon Apr 28 01:06:22 2014 : Info: rlm_sql (sql): Closing sqlsocket 0 Mon Apr 28 01:06:25 2014 : Info: rlm_sql (sql): Driver rlm_sql_mysql (module rlm_sql_mysql) loaded and linked Mon Apr 28 01:06:25 2014 : Info: rlm_sql (sql): Attempting to connect to userfreeradius@localhost:/freeradius Mon Apr 28 01:06:25 2014 : Info: rlm_sql (sql): Attempting to connect rlm_sql_mysql #0 Mon Apr 28 01:06:25 2014 : Info: rlm_sql_mysql: Starting connect to MySQL server for #0 Mon Apr 28 01:06:25 2014 : Info: rlm_sql (sql): Connected new DB handle, #0 Mon Apr 28 01:06:25 2014 : Info: rlm_sql (sql): Attempting to connect rlm_sql_mysql #1 Mon Apr 28 01:06:25 2014 : Info: rlm_sql_mysql: Starting connect to MySQL server for #1 Mon Apr 28 01:06:25 2014 : Info: rlm_sql (sql): Connected new DB handle, #1 Mon Apr 28 01:06:25 2014 : Info: rlm_sql (sql): Attempting to connect rlm_sql_mysql #2 Mon Apr 28 01:06:25 2014 : Info: rlm_sql_mysql: Starting connect to MySQL server for #2 Mon Apr 28 01:06:25 2014 : Info: rlm_sql (sql): Connected new DB handle, #2 Mon Apr 28 01:06:25 2014 : Info: rlm_sql (sql): Attempting to connect rlm_sql_mysql #3 Mon Apr 28 01:06:25 2014 : Info: rlm_sql_mysql: Starting connect to MySQL server for #3 Mon Apr 28 01:06:25 2014 : Info: rlm_sql (sql): Connected new DB handle, #3 Mon Apr 28 01:06:25 2014 : Info: rlm_sql (sql): Attempting to connect rlm_sql_mysql #4 Mon Apr 28 01:06:25 2014 : Info: rlm_sql_mysql: Starting connect to MySQL server for #4 Mon Apr 28 01:06:25 2014 : Info: rlm_sql (sql): Connected new DB handle, #4 Mon Apr 28 01:06:25 2014 : Info: rlm_sql (sql): Attempting to connect rlm_sql_mysql #5 Mon Apr 28 01:06:25 2014 : Info: rlm_sql_mysql: Starting connect to MySQL server for #5 Mon Apr 28 01:06:25 2014 : Info: rlm_sql (sql): Connected new DB handle, #5 Mon Apr 28 01:06:25 2014 : Info: rlm_sql (sql): Attempting to connect rlm_sql_mysql #6 Mon Apr 28 01:06:25 2014 : Info: rlm_sql_mysql: Starting connect to MySQL server for #6 Mon Apr 28 01:06:25 2014 : Info: rlm_sql (sql): Connected new DB handle, #6 Mon Apr 28 01:06:25 2014 : Info: rlm_sql (sql): Attempting to connect rlm_sql_mysql #7 Mon Apr 28 01:06:25 2014 : Info: rlm_sql_mysql: Starting connect to MySQL server for #7 Mon Apr 28 01:06:25 2014 : Info: rlm_sql (sql): Connected new DB handle, #7 Mon Apr 28 01:06:25 2014 : Info: rlm_sql (sql): Attempting to connect rlm_sql_mysql #8 Mon Apr 28 01:06:25 2014 : Info: rlm_sql_mysql: Starting connect to MySQL server for #8 Mon Apr 28 01:06:25 2014 : Info: rlm_sql (sql): Connected new DB handle, #8 Mon Apr 28 01:06:25 2014 : Info: rlm_sql (sql): Attempting to connect rlm_sql_mysql #9 Mon Apr 28 01:06:25 2014 : Info: rlm_sql_mysql: Starting connect to MySQL server for #9 Mon Apr 28 01:06:25 2014 : Info: rlm_sql (sql): Connected new DB handle, #9 Mon Apr 28 01:06:25 2014 : Info: rlm_sql (sql): Attempting to connect rlm_sql_mysql #10 Mon Apr 28 01:06:25 2014 : Info: rlm_sql_mysql: Starting connect to MySQL server for #10 Mon Apr 28 01:06:25 2014 : Info: rlm_sql (sql): Connected new DB handle, #10 Mon Apr 28 01:06:25 2014 : Info: rlm_sql (sql): Attempting to connect rlm_sql_mysql #11 Mon Apr 28 01:06:25 2014 : Info: rlm_sql_mysql: Starting connect to MySQL server for #11 Mon Apr 28 01:06:25 2014 : Info: rlm_sql (sql): Connected new DB handle, #11 Mon Apr 28 01:06:25 2014 : Info: rlm_sql (sql): Attempting to connect rlm_sql_mysql #12 Mon Apr 28 01:06:25 2014 : Info: rlm_sql_mysql: Starting connect to MySQL server for #12 Mon Apr 28 01:06:25 2014 : Info: rlm_sql (sql): Connected new DB handle, #12 Mon Apr 28 01:06:25 2014 : Info: rlm_sql (sql): Attempting to connect rlm_sql_mysql #13 Mon Apr 28 01:06:25 2014 : Info: rlm_sql_mysql: Starting connect to MySQL server for #13 Mon Apr 28 01:06:25 2014 : Info: rlm_sql (sql): Connected new DB handle, #13 Mon Apr 28 01:06:25 2014 : Info: rlm_sql (sql): Attempting to connect rlm_sql_mysql #14 Mon Apr 28 01:06:25 2014 : Info: rlm_sql_mysql: Starting connect to MySQL server for #14 Mon Apr 28 01:06:25 2014 : Info: rlm_sql (sql): Connected new DB handle, #14 Mon Apr 28 01:06:25 2014 : Info: Loaded virtual server <default> Mon Apr 28 01:06:25 2014 : Info: Loaded virtual server inner-tunnel Mon Apr 28 01:06:25 2014 : Info: ... adding new socket proxy address * port 47655 Mon Apr 28 01:06:25 2014 : Info: Ready to process requests. ------------------------------------------ Thanks.
I will put an additional log.It was gotten same situation. Any advice will help me! -----------------radiusd -X--------------------- Listening on authentication address * port 1812 Listening on accounting address * port 1813 Listening on command file /var/run/radiusd/radiusd.sock Listening on authentication address 127.0.0.1 port 18120 as server inner-tunnel Listening on proxy address * port 1814 Ready to process requests. rad_recv: Access-Request packet from host 10.0.5.200 port 50000, id=9, length=205 User-Password = "test" User-Name = "user@mondomaine.fr" Acct-Session-Id = "erx FastEthernet 1/6:0012582922" Service-Type = Framed-User Framed-Protocol = PPP ERX-Pppoe-Description = "pppoe 00:1d:72:c6:7b:d5" Calling-Station-Id = "#ERX-40-b0-7a#E16#0" NAS-Port-Type = Ethernet NAS-Port = 369098752 NAS-Port-Id = "FastEthernet 1/6" NAS-IP-Address = 10.0.5.200 NAS-Identifier = "ERX-40-b0-7a" # Executing section authorize from file /etc/raddb/sites-enabled/default +- entering group authorize {...} ++[preprocess] returns ok ++[chap] returns noop ++[mschap] returns noop ++[digest] returns noop [suffix] Looking up realm "mondomaine.fr" for User-Name = " user@mondomaine.fr" [suffix] No such realm "mondomaine.fr" ++[suffix] returns noop [eap] No EAP-Message, not doing EAP ++[eap] returns noop [files] users: Matched entry DEFAULT at line 1 [files] users: Matched entry user@mondomaine.fr at line 10 [files] users: Matched entry DEFAULT at line 187 ++[files] returns ok ++[expiration] returns noop ++[logintime] returns noop ++[pap] returns updated Found Auth-Type = PAP # Executing group from file /etc/raddb/sites-enabled/default +- entering group PAP {...} [pap] login attempt with password "test" [pap] Using clear text password "test" [pap] User authenticated successfully ++[pap] returns ok Login OK: [user@mondomaine.fr] (from client GGSN1 port 369098752 cli #ERX-40-b0-7a#E16#0) # Executing section post-auth from file /etc/raddb/sites-enabled/default +- entering group post-auth {...} rlm_sql (sql): Reserving sql socket id: 13 [sqlippool] expand: %{User-Name} -> user@mondomaine.fr [sqlippool] sql_set_user escaped user --> 'user@mondomaine.fr' [sqlippool] expand: START TRANSACTION -> START TRANSACTION [sqlippool] expand: UPDATE radippool SET nasipaddress = '', pool_key = 0, callingstationid = '', username = '', expiry_time = NULL WHERE expiry_time <= NOW() - INTERVAL 1 SECOND AND nasipaddress = '%{Nas-IP-Address}' -> UPDATE radippool SET nasipaddress = '', pool_key = 0, callingstationid = '', username = '', expiry_time = NULL WHERE expiry_time <= NOW() - INTERVAL 1 SECOND AND nasipaddress = '10.0.5.200' [sqlippool] expand: SELECT framedipaddress FROM radippool WHERE pool_name = '%{control:Pool-Name}' AND (expiry_time < NOW() OR expiry_time IS NULL) ORDER BY (username <> '%{User-Name}'), (callingstationid <> '%{Calling-Station-Id}'), expiry_time LIMIT 1 FOR UPDATE -> SELECT framedipaddress FROM radippool WHERE pool_name = 'pool1' AND (expiry_time < NOW() OR expiry_time IS NULL) ORDER BY (username <> 'user@mondomaine.fr'), (callingstationid <> '=23ERX-40-b0-7a=23E16=230'), expiry_time LIMIT 1 FOR UPDATE [sqlippool] expand: UPDATE radippool SET nasipaddress = '%{NAS-IP-Address}', pool_key = '%{NAS-Port}', callingstationid = '%{Calling-Station-Id}', username = '%{User-Name}', expiry_time = NOW() + INTERVAL 3600 SECOND WHERE framedipaddress = '192.168.0.1' AND expiry_time IS NULL -> UPDATE radippool SET nasipaddress = '10.0.5.200', pool_key = '369098752', callingstationid = '=23ERX-40-b0-7a=23E16=230', username = ' user@mondomaine.fr', expiry_time = NOW() + INTERVAL 3600 SECOND WHERE framedipaddress = '192.168.0.1' AND expiry_time IS NULL [sqlippool] Allocated IP 192.168.0.1 [0100a8c0] [sqlippool] expand: COMMIT -> COMMIT rlm_sql (sql): Released sql socket id: 13 [sqlippool] expand: Allocated IP: %{reply:Framed-IP-Address} from %{control:Pool-Name} (did %{Called-Station-Id} cli %{Calling-Station-Id} port %{NAS-Port} user %{User-Name}) -> Allocated IP: 192.168.0.1 from pool1 (did cli #ERX-40-b0-7a#E16#0 port 369098752 user user@mondomaine.fr) Allocated IP: 192.168.0.1 from pool1 (did cli #ERX-40-b0-7a#E16#0 port 369098752 user user@mondomaine.fr) ++[sqlippool] returns ok ++[exec] returns noop Sending Access-Accept of id 9 to 10.0.5.200 port 50000 NAS-IP-Address == 10.0.5.200 Framed-Protocol = PPP Framed-Compression = Van-Jacobson-TCP-IP Framed-IP-Address = 192.168.0.1 Finished request 0. Going to the next request Waking up in 4.9 seconds. rad_recv: Accounting-Request packet from host 10.0.5.200 port 50016, id=85, length=229 Acct-Status-Type = Start User-Name = "user@mondomaine.fr" Event-Timestamp = "Apr 27 2014 16:26:33 PDT" Acct-Delay-Time = 0 NAS-Identifier = "ERX-40-b0-7a" Acct-Session-Id = "erx FastEthernet 1/6:0012582922" NAS-IP-Address = 10.0.5.200 Service-Type = Framed-User Framed-Protocol = PPP Framed-Compression = None ERX-Pppoe-Description = "pppoe 00:1d:72:c6:7b:d5" Framed-IP-Address = 192.168.0.1 Framed-IP-Netmask = 255.255.255.255 Calling-Station-Id = "#ERX-40-b0-7a#E16#0" NAS-Port-Type = Ethernet NAS-Port = 369098752 NAS-Port-Id = "FastEthernet 1/6" Acct-Authentic = RADIUS # Executing section preacct from file /etc/raddb/sites-enabled/default +- entering group preacct {...} ++[preprocess] returns ok [acct_unique] Hashing 'NAS-Port = 369098752,Client-IP-Address = 10.0.5.200,NAS-IP-Address = 10.0.5.200,Acct-Session-Id = "erx FastEthernet 1/6:0012582922",User-Name = "user@mondomaine.fr"' [acct_unique] Acct-Unique-Session-ID = "b3e57c6c1b5cc9ca". ++[acct_unique] returns ok [suffix] Looking up realm "mondomaine.fr" for User-Name = " user@mondomaine.fr" [suffix] No such realm "mondomaine.fr" ++[suffix] returns noop ++[files] returns noop # Executing section accounting from file /etc/raddb/sites-enabled/default +- entering group accounting {...} [detail] expand: %{Packet-Src-IP-Address} -> 10.0.5.200 [detail] expand: /var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d -> /var/log/radius/radacct/10.0.5.200/detail-20140428 [detail] /var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d expands to /var/log/radius/radacct/10.0.5.200/detail-20140428 [detail] expand: %t -> Mon Apr 28 00:56:37 2014 ++[detail] returns ok ++[unix] returns ok [radutmp] expand: /var/log/radius/radutmp -> /var/log/radius/radutmp [radutmp] expand: %{User-Name} -> user@mondomaine.fr ++[radutmp] returns ok rlm_sql (sql): Reserving sql socket id: 12 [sqlippool] expand: %{User-Name} -> user@mondomaine.fr [sqlippool] sql_set_user escaped user --> 'user@mondomaine.fr' [sqlippool] expand: START TRANSACTION -> START TRANSACTION [sqlippool] expand: UPDATE radippool SET expiry_time = NOW() + INTERVAL 3600 SECOND WHERE nasipaddress = '%{NAS-IP-Address}' AND pool_key = '%{NAS-Port}' AND username = '%{User-Name}' AND callingstationid = '%{Calling-Station-Id}' AND framedipaddress = '%{Framed-IP-Address}' -> UPDATE radippool SET expiry_time = NOW() + INTERVAL 3600 SECOND WHERE nasipaddress = '10.0.5.200' AND pool_key = '369098752' AND username = 'user@mondomaine.fr' AND callingstationid = '=23ERX-40-b0-7a=23E16=230' AND framedipaddress = '192.168.0.1' [sqlippool] expand: COMMIT -> COMMIT rlm_sql (sql): Released sql socket id: 12 ++[sqlippool] returns ok ++[exec] returns noop [attr_filter.accounting_response] expand: %{User-Name} -> user@mondomaine.fr attr_filter: Matched entry DEFAULT at line 12 ++[attr_filter.accounting_response] returns updated Sending Accounting-Response of id 85 to 10.0.5.200 port 50016 Finished request 1. Cleaning up request 1 ID 85 with timestamp +6 Going to the next request Waking up in 4.9 seconds. Cleaning up request 0 ID 9 with timestamp +6 Ready to process requests. rad_recv: Accounting-Request packet from host 10.0.5.200 port 50016, id=86, length=301 Acct-Status-Type = Stop User-Name = "user@mondomaine.fr" Event-Timestamp = "Apr 27 2014 16:26:41 PDT" Acct-Delay-Time = 0 NAS-Identifier = "ERX-40-b0-7a" Acct-Session-Id = "erx FastEthernet 1/6:0012582922" NAS-IP-Address = 10.0.5.200 Service-Type = Framed-User Framed-Protocol = PPP Framed-Compression = None ERX-Pppoe-Description = "pppoe 00:1d:72:c6:7b:d5" Framed-IP-Address = 192.168.0.1 Framed-IP-Netmask = 255.255.255.255 Calling-Station-Id = "#ERX-40-b0-7a#E16#0" Acct-Input-Gigawords = 0 Acct-Input-Octets = 280 Acct-Output-Gigawords = 0 Acct-Output-Octets = 54 ERX-Input-Gigapkts = 0 Acct-Input-Packets = 0 ERX-Output-Gigapkts = 0 Acct-Output-Packets = 0 NAS-Port-Type = Ethernet NAS-Port = 369098752 NAS-Port-Id = "FastEthernet 1/6" Acct-Authentic = RADIUS Acct-Session-Time = 8 Acct-Terminate-Cause = User-Request # Executing section preacct from file /etc/raddb/sites-enabled/default +- entering group preacct {...} ++[preprocess] returns ok [acct_unique] Hashing 'NAS-Port = 369098752,Client-IP-Address = 10.0.5.200,NAS-IP-Address = 10.0.5.200,Acct-Session-Id = "erx FastEthernet 1/6:0012582922",User-Name = "user@mondomaine.fr"' [acct_unique] Acct-Unique-Session-ID = "b3e57c6c1b5cc9ca". ++[acct_unique] returns ok [suffix] Looking up realm "mondomaine.fr" for User-Name = " user@mondomaine.fr" [suffix] No such realm "mondomaine.fr" ++[suffix] returns noop ++[files] returns noop # Executing section accounting from file /etc/raddb/sites-enabled/default +- entering group accounting {...} [detail] expand: %{Packet-Src-IP-Address} -> 10.0.5.200 [detail] expand: /var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d -> /var/log/radius/radacct/10.0.5.200/detail-20140428 [detail] /var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d expands to /var/log/radius/radacct/10.0.5.200/detail-20140428 [detail] expand: %t -> Mon Apr 28 00:56:45 2014 ++[detail] returns ok ++[unix] returns ok [radutmp] expand: /var/log/radius/radutmp -> /var/log/radius/radutmp [radutmp] expand: %{User-Name} -> user@mondomaine.fr ++[radutmp] returns ok rlm_sql (sql): Reserving sql socket id: 11 [sqlippool] expand: %{User-Name} -> user@mondomaine.fr [sqlippool] sql_set_user escaped user --> 'user@mondomaine.fr' [sqlippool] expand: START TRANSACTION -> START TRANSACTION [sqlippool] expand: UPDATE radippool SET nasipaddress = '', pool_key = 0, callingstationid = '', username = '', expiry_time = NULL WHERE nasipaddress = '%{Nas-IP-Address}' AND pool_key = '%{NAS-Port}' AND username = '%{User-Name}' AND callingstationid = '%{Calling-Station-Id}' AND framedipaddress = '%{Framed-IP-Address}' -> UPDATE radippool SET nasipaddress = '', pool_key = 0, callingstationid = '', username = '', expiry_time = NULL WHERE nasipaddress = '10.0.5.200' AND pool_key = '369098752' AND username = 'user@mondomaine.fr' AND callingstationid = '=23ERX-40-b0-7a=23E16=230' AND framedipaddress = '192.168.0.1' [sqlippool] expand: COMMIT -> COMMIT [sqlippool] expand: Released IP %{Framed-IP-Address} (did %{Called-Station-Id} cli %{Calling-Station-Id} user %{User-Name}) -> Released IP 192.168.0.1 (did cli #ERX-40-b0-7a#E16#0 user user@mondomaine.fr) Released IP 192.168.0.1 (did cli #ERX-40-b0-7a#E16#0 user user@mondomaine.fr) rlm_sql (sql): Released sql socket id: 11 ++[sqlippool] returns ok ++[exec] returns noop [attr_filter.accounting_response] expand: %{User-Name} -> user@mondomaine.fr attr_filter: Matched entry DEFAULT at line 12 ++[attr_filter.accounting_response] returns updated Sending Accounting-Response of id 86 to 10.0.5.200 port 50016 Finished request 2. Cleaning up request 2 ID 86 with timestamp +14 Going to the next request Ready to process requests. [root@localhost ~]# ------------------------------------------------- Thanks 2014-04-28 18:43 GMT+09:00 yata <aurens.memuro02@gmail.com>:
Hi!
I wanna freeradius2 as a dhcp-server When I connect to freeradius-server from laptop (Windows Vista) via ERX310 by using PPPoE Following massages appeared. On the laptop I saw an error message "*Error 734: The PPP link control protocol was terminated."* What's wrong with my configuration? Please suggest to me what information should I provide you.
---------------------------raius.log---------------------------------- Mon Apr 28 01:05:03 2014 : Info: ... adding new socket proxy address * port 36233 Mon Apr 28 01:05:03 2014 : Info: Ready to process requests. Mon Apr 28 01:06:11 2014 : Auth: Login OK: [user@mondomaine.fr] (from client GGSN1 port 369098752 cli #ERX-40-b0-7a#E16#0) Mon Apr 28 01:06:11 2014 : Info: Allocated IP: 192.168.0.1 from pool1 (did cli #ERX-40-b0-7a#E16#0 port 369098752 user user@mondomaine.fr) Mon Apr 28 01:06:18 2014 : Info: Released IP 192.168.0.1 (did cli #ERX-40-b0-7a#E16#0 user user@mondomaine.fr) Mon Apr 28 01:06:22 2014 : Info: Signalled to terminate Mon Apr 28 01:06:22 2014 : Info: Exiting normally. Mon Apr 28 01:06:22 2014 : Info: rlm_sql (sql): Closing sqlsocket 14 Mon Apr 28 01:06:22 2014 : Info: rlm_sql (sql): Closing sqlsocket 13 Mon Apr 28 01:06:22 2014 : Info: rlm_sql (sql): Closing sqlsocket 12 Mon Apr 28 01:06:22 2014 : Info: rlm_sql (sql): Closing sqlsocket 11 Mon Apr 28 01:06:22 2014 : Info: rlm_sql (sql): Closing sqlsocket 10 Mon Apr 28 01:06:22 2014 : Info: rlm_sql (sql): Closing sqlsocket 9 Mon Apr 28 01:06:22 2014 : Info: rlm_sql (sql): Closing sqlsocket 8 Mon Apr 28 01:06:22 2014 : Info: rlm_sql (sql): Closing sqlsocket 7 Mon Apr 28 01:06:22 2014 : Info: rlm_sql (sql): Closing sqlsocket 6 Mon Apr 28 01:06:22 2014 : Info: rlm_sql (sql): Closing sqlsocket 5 Mon Apr 28 01:06:22 2014 : Info: rlm_sql (sql): Closing sqlsocket 4 Mon Apr 28 01:06:22 2014 : Info: rlm_sql (sql): Closing sqlsocket 3 Mon Apr 28 01:06:22 2014 : Info: rlm_sql (sql): Closing sqlsocket 2 Mon Apr 28 01:06:22 2014 : Info: rlm_sql (sql): Closing sqlsocket 1 Mon Apr 28 01:06:22 2014 : Info: rlm_sql (sql): Closing sqlsocket 0 Mon Apr 28 01:06:25 2014 : Info: rlm_sql (sql): Driver rlm_sql_mysql (module rlm_sql_mysql) loaded and linked Mon Apr 28 01:06:25 2014 : Info: rlm_sql (sql): Attempting to connect to userfreeradius@localhost:/freeradius Mon Apr 28 01:06:25 2014 : Info: rlm_sql (sql): Attempting to connect rlm_sql_mysql #0 Mon Apr 28 01:06:25 2014 : Info: rlm_sql_mysql: Starting connect to MySQL server for #0 Mon Apr 28 01:06:25 2014 : Info: rlm_sql (sql): Connected new DB handle, #0 Mon Apr 28 01:06:25 2014 : Info: rlm_sql (sql): Attempting to connect rlm_sql_mysql #1 Mon Apr 28 01:06:25 2014 : Info: rlm_sql_mysql: Starting connect to MySQL server for #1 Mon Apr 28 01:06:25 2014 : Info: rlm_sql (sql): Connected new DB handle, #1 Mon Apr 28 01:06:25 2014 : Info: rlm_sql (sql): Attempting to connect rlm_sql_mysql #2 Mon Apr 28 01:06:25 2014 : Info: rlm_sql_mysql: Starting connect to MySQL server for #2 Mon Apr 28 01:06:25 2014 : Info: rlm_sql (sql): Connected new DB handle, #2 Mon Apr 28 01:06:25 2014 : Info: rlm_sql (sql): Attempting to connect rlm_sql_mysql #3 Mon Apr 28 01:06:25 2014 : Info: rlm_sql_mysql: Starting connect to MySQL server for #3 Mon Apr 28 01:06:25 2014 : Info: rlm_sql (sql): Connected new DB handle, #3 Mon Apr 28 01:06:25 2014 : Info: rlm_sql (sql): Attempting to connect rlm_sql_mysql #4 Mon Apr 28 01:06:25 2014 : Info: rlm_sql_mysql: Starting connect to MySQL server for #4 Mon Apr 28 01:06:25 2014 : Info: rlm_sql (sql): Connected new DB handle, #4 Mon Apr 28 01:06:25 2014 : Info: rlm_sql (sql): Attempting to connect rlm_sql_mysql #5 Mon Apr 28 01:06:25 2014 : Info: rlm_sql_mysql: Starting connect to MySQL server for #5 Mon Apr 28 01:06:25 2014 : Info: rlm_sql (sql): Connected new DB handle, #5 Mon Apr 28 01:06:25 2014 : Info: rlm_sql (sql): Attempting to connect rlm_sql_mysql #6 Mon Apr 28 01:06:25 2014 : Info: rlm_sql_mysql: Starting connect to MySQL server for #6 Mon Apr 28 01:06:25 2014 : Info: rlm_sql (sql): Connected new DB handle, #6 Mon Apr 28 01:06:25 2014 : Info: rlm_sql (sql): Attempting to connect rlm_sql_mysql #7 Mon Apr 28 01:06:25 2014 : Info: rlm_sql_mysql: Starting connect to MySQL server for #7 Mon Apr 28 01:06:25 2014 : Info: rlm_sql (sql): Connected new DB handle, #7 Mon Apr 28 01:06:25 2014 : Info: rlm_sql (sql): Attempting to connect rlm_sql_mysql #8 Mon Apr 28 01:06:25 2014 : Info: rlm_sql_mysql: Starting connect to MySQL server for #8 Mon Apr 28 01:06:25 2014 : Info: rlm_sql (sql): Connected new DB handle, #8 Mon Apr 28 01:06:25 2014 : Info: rlm_sql (sql): Attempting to connect rlm_sql_mysql #9 Mon Apr 28 01:06:25 2014 : Info: rlm_sql_mysql: Starting connect to MySQL server for #9 Mon Apr 28 01:06:25 2014 : Info: rlm_sql (sql): Connected new DB handle, #9 Mon Apr 28 01:06:25 2014 : Info: rlm_sql (sql): Attempting to connect rlm_sql_mysql #10 Mon Apr 28 01:06:25 2014 : Info: rlm_sql_mysql: Starting connect to MySQL server for #10 Mon Apr 28 01:06:25 2014 : Info: rlm_sql (sql): Connected new DB handle, #10 Mon Apr 28 01:06:25 2014 : Info: rlm_sql (sql): Attempting to connect rlm_sql_mysql #11 Mon Apr 28 01:06:25 2014 : Info: rlm_sql_mysql: Starting connect to MySQL server for #11 Mon Apr 28 01:06:25 2014 : Info: rlm_sql (sql): Connected new DB handle, #11 Mon Apr 28 01:06:25 2014 : Info: rlm_sql (sql): Attempting to connect rlm_sql_mysql #12 Mon Apr 28 01:06:25 2014 : Info: rlm_sql_mysql: Starting connect to MySQL server for #12 Mon Apr 28 01:06:25 2014 : Info: rlm_sql (sql): Connected new DB handle, #12 Mon Apr 28 01:06:25 2014 : Info: rlm_sql (sql): Attempting to connect rlm_sql_mysql #13 Mon Apr 28 01:06:25 2014 : Info: rlm_sql_mysql: Starting connect to MySQL server for #13 Mon Apr 28 01:06:25 2014 : Info: rlm_sql (sql): Connected new DB handle, #13 Mon Apr 28 01:06:25 2014 : Info: rlm_sql (sql): Attempting to connect rlm_sql_mysql #14 Mon Apr 28 01:06:25 2014 : Info: rlm_sql_mysql: Starting connect to MySQL server for #14 Mon Apr 28 01:06:25 2014 : Info: rlm_sql (sql): Connected new DB handle, #14 Mon Apr 28 01:06:25 2014 : Info: Loaded virtual server <default> Mon Apr 28 01:06:25 2014 : Info: Loaded virtual server inner-tunnel Mon Apr 28 01:06:25 2014 : Info: ... adding new socket proxy address * port 47655 Mon Apr 28 01:06:25 2014 : Info: Ready to process requests. ------------------------------------------
Thanks.
Hi Alan Thanks for reply. I understand PPPoE server, or the end user disconnected. you mean PPPoE server is Nas-client? In my case ERX310? If so I manage it, So What Should I do with ERX310? 2014-04-29 7:25 GMT+09:00 Alan DeKok <aland@deployingradius.com>:
yata wrote:
I will put an additional log.It was gotten same situation. Any advice will help me!
The PPPoE server, or the end user, is hanging up the connection after 3-4 seconds.
Go ask the PPPoE server why it's not giving the user access.
Alan DeKok. - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
yata wrote:
Hi Alan
Thanks for reply. I understand PPPoE server, or the end user disconnected. you mean PPPoE server is Nas-client? In my case ERX310? If so I manage it, So What Should I do with ERX310?
Find out why it's closing the user session. The problem is not RADIUS. You're looking at the RADIUS logs, and seeing that the session was closed. But RADIUS didn't close the connection. The PPPoE server closed the connection. Then, the PPPoE server told RADIUS it closed the connection. Alan DeKok.
Hi Alan I found that wrong configuration of PPPoE server and IP address was assigned. Thank you so much for your help! 2014-04-29 23:16 GMT+09:00 Alan DeKok <aland@deployingradius.com>:
yata wrote:
Hi Alan
Thanks for reply. I understand PPPoE server, or the end user disconnected. you mean PPPoE server is Nas-client? In my case ERX310? If so I manage it, So What Should I do with ERX310?
Find out why it's closing the user session.
The problem is not RADIUS. You're looking at the RADIUS logs, and seeing that the session was closed. But RADIUS didn't close the connection. The PPPoE server closed the connection. Then, the PPPoE server told RADIUS it closed the connection.
Alan DeKok. - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
participants (2)
-
Alan DeKok -
yata