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.