freeradius 3

[kosmich]

Ты показал лог радиуса именно в тот момент, когда pppoe сервер выдал ошибку "от радиуса получен некорректный ответ"?

Да, именно так. И так по кругу.

А вот так завершается "неправильная" сессия и начинается "правильная" с динамическим айпи.

Код:

Ready to process requests
(0) Received Access-Request Id 253 from 127.0.0.1:25058 to 
127.0.0.1:1812 length 202
(0)   NAS-Identifier = "nas01"
(0)   NAS-IP-Address = 127.0.0.1
(0)   Message-Authenticator = 0x45c07bd2558b1de9d637f95b1d249178
(0)   Acct-Session-Id = "9051986-vlan254-41"
(0)   NAS-Port = 41
(0)   NAS-Port-Type = Ethernet
(0)   Service-Type = Framed-User
(0)   Framed-Protocol = PPP
(0)   Calling-Station-Id = "d4da7687a4f5"
(0)   NAS-Port-Id = "vlan254"
(0)   Attr-26.12341.12 = 0x766c616e36302d3431
(0)   Tunnel-Medium-Type:0 = IEEE-802
(0)   Tunnel-Client-Endpoint:0 = "d4:da:76:87:a4:f5"
(0)   User-Name = "ppp_test"
(0)   User-Password = "ppp_test"
(0) # Executing section authorize from file 
/usr/local/etc/raddb/sites-enabled/nodeny
(0)   authorize {
rlm_sql (sql): Closing connection (0): Hit idle_timeout, was idle for 77 
seconds
rlm_sql (sql): You probably need to lower "min"
rlm_sql_mysql: Socket destructor called, closing socket
rlm_sql (sql): Closing connection (1): Hit idle_timeout, was idle for 77 
seconds
rlm_sql (sql): You probably need to lower "min"
rlm_sql_mysql: Socket destructor called, closing socket
rlm_sql (sql): Closing connection (2): Hit idle_timeout, was idle for 77 
seconds
rlm_sql (sql): You probably need to lower "min"
rlm_sql_mysql: Socket destructor called, closing socket
rlm_sql (sql): Closing connection (3): Hit idle_timeout, was idle for 77 
seconds
rlm_sql (sql): You probably need to lower "min"
rlm_sql_mysql: Socket destructor called, closing socket
rlm_sql (sql): Closing connection (4): Hit idle_timeout, was idle for 77 
seconds
rlm_sql (sql): You probably need to lower "min"
rlm_sql_mysql: Socket destructor called, closing socket
rlm_sql (sql): 0 of 0 connections in use.  You  may need to increase "spare"
rlm_sql (sql): Opening additional connection (5), 1 of 10 pending slots used
rlm_sql_mysql: Starting connect to MySQL server
rlm_sql_mysql: Connected to database 'nodeny' on Localhost via UNIX 
socket, server version 5.6.39, protocol version 10
rlm_sql (sql): Reserved connection (5)
(0) sql: EXPAND call radcheck('%{User-Name}')
(0) sql:    --> call radcheck('ppp_test')
(0) sql: Executing select query: call radcheck('ppp_test')
(0) sql: User found in radcheck table
(0) sql: Conditional check items matched, merging assignment check items
(0) sql:   Cleartext-Password := "ppp_test"
(0) sql: EXPAND call radreply('%{User-Name}')
(0) sql:    --> call radreply('ppp_test')
(0) sql: Executing select query: call radreply('ppp_test')
(0) sql: User found in radreply table, merging reply items
(0) sql:   Framed-IP-Address = 10.0.0.3
(0) sql:   Framed-IP-Netmask = 255.255.255.255
(0) sql:   Framed-Protocol = PPP
rlm_sql (sql): Released connection (5)
Need 4 more connections to reach min connections (5)
rlm_sql (sql): Opening additional connection (6), 1 of 9 pending slots used
rlm_sql_mysql: Starting connect to MySQL server
rlm_sql_mysql: Connected to database 'nodeny' on Localhost via UNIX 
socket, server version 5.6.39, protocol version 10
(0)     [sql] = ok
(0)     [pap] = updated
(0)     [chap] = noop
(0)     [mschap] = noop
(0)   } # authorize = updated
(0) Found Auth-Type = PAP
(0) # Executing group from file /usr/local/etc/raddb/sites-enabled/nodeny
(0)   Auth-Type PAP {
(0) pap: Login attempt with password
(0) pap: Comparing with "known good" Cleartext-Password
(0) pap: User authenticated successfully
(0)     [pap] = ok
(0)   } # Auth-Type PAP = ok
(0) # Executing section post-auth from file 
/usr/local/etc/raddb/sites-enabled/nodeny
(0)   post-auth {
(0) sql: EXPAND .query
(0) sql:    --> .query
(0) sql: Using query template 'query'
rlm_sql (sql): Reserved connection (5)
(0) sql: EXPAND call 
radupdate('%{User-Name}','%{reply:Framed-IP-Address}', 
'user=%{Calling-Station-Id};nas=%{NAS-IP-Address}')
(0) sql:    --> call radupdate('ppp_test','10.0.0.3', 
'user=d4da7687a4f5;nas=127.0.0.1')
(0) sql: Executing query: call radupdate('ppp_test','10.0.0.3', 
'user=d4da7687a4f5;nas=127.0.0.1')
(0) sql: SQL query returned: success
(0) sql: 1 record(s) updated
rlm_sql (sql): Released connection (5)
(0)     [sql] = ok
(0)   } # post-auth = ok
(0) Sent Access-Accept Id 253 from 127.0.0.1:1812 to 127.0.0.1:25058 
length 0
(0)   Framed-IP-Address = 10.0.0.3
(0)   Framed-IP-Netmask = 255.255.255.255
(0)   Framed-Protocol = PPP
(0) Finished request
Waking up in 4.9 seconds.
(1) Received Accounting-Request Id 248 from 127.0.0.1:54567 to 
127.0.0.1:1813 length 297
(1)   NAS-Identifier = "nas01"
(1)   NAS-IP-Address = 127.0.0.1
(1)   Acct-Session-Id = "9051986-vlan254-41"
(1)   NAS-Port = 41
(1)   NAS-Port-Type = Ethernet
(1)   Service-Type = Framed-User
(1)   Framed-Protocol = PPP
(1)   Calling-Station-Id = "d4da7687a4f5"
(1)   NAS-Port-Id = "vlan254"
(1)   Attr-26.12341.12 = 0x766c616e36302d3431
(1)   Attr-26.12341.19 = 0x4d535241532d302d303661346537
(1)   Tunnel-Medium-Type:0 = IEEE-802
(1)   Tunnel-Client-Endpoint:0 = "d4:da:76:87:a4:f5"
(1)   Acct-Status-Type = Start
(1)   Framed-IP-Address = 10.0.0.3
(1)   Framed-IP-Netmask = 255.255.255.255
(1)   Framed-IPv6-Address = ::
(1)   User-Name = "ppp_test"
(1)   Acct-Multi-Session-Id = "9051987-B-1"
(1)   Attr-26.12341.13 = 0x422d31
(1)   Attr-26.12341.14 = 0x6e6730
(1)   Attr-26.12341.15 = 0x0000000b
(1)   Attr-26.12341.19 = 0x4d535241532d302d303661346537
(1)   Acct-Link-Count = 1
(1)   Acct-Authentic = RADIUS
(1) # Executing section preacct from file 
/usr/local/etc/raddb/sites-enabled/nodeny
(1)   preacct {
(1)     policy acct_unique {
(1)       update request {
(1)         &Tmp-String-9 := "ai:"
(1)       } # update request = noop
(1)       if (("%{hex:&Class}" =~ /^%{hex:&Tmp-String-9}/) &&         
("%{string:&Class}" =~ /^ai:([0-9a-f]{32})/i)) {
(1)       EXPAND %{hex:&Class}
(1)          -->
(1)       EXPAND ^%{hex:&Tmp-String-9}
(1)          --> ^61693a
(1)       if (("%{hex:&Class}" =~ /^%{hex:&Tmp-String-9}/) &&         
("%{string:&Class}" =~ /^ai:([0-9a-f]{32})/i))  -> FALSE
(1)       else {
(1)         update request {
(1)           EXPAND 
%{md5:%{User-Name},%{Acct-Session-ID},%{%{NAS-IPv6-Address}:-%{NAS-IP-Address}},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}}
(1)              --> 6aa8f750d3c9e22993188729cd4bb391
(1)           &Acct-Unique-Session-Id := 6aa8f750d3c9e22993188729cd4bb391
(1)         } # update request = noop
(1)       } # else = noop
(1)     } # policy acct_unique = noop
(1)     [preprocess] = ok
(1)   } # preacct = ok
(1) # Executing section accounting from file 
/usr/local/etc/raddb/sites-enabled/nodeny
(1)   accounting {
(1) sql: EXPAND .query
(1) sql:    --> .query
(1) sql: Using query template 'query'
rlm_sql (sql): Reserved connection (6)
(1) sql: EXPAND call radupdate('%{User-Name}','%{Framed-IP-Address}', 
'user=%{Calling-Station-Id};nas=%{NAS-IP-Address}')
(1) sql:    --> call radupdate('ppp_test','10.0.0.3', 
'user=d4da7687a4f5;nas=127.0.0.1')
(1) sql: Executing query: call radupdate('ppp_test','10.0.0.3', 
'user=d4da7687a4f5;nas=127.0.0.1')
(1) sql: SQL query returned: success
(1) sql: 1 record(s) updated
rlm_sql (sql): Released connection (6)
Need 3 more connections to reach min connections (5)
rlm_sql (sql): Opening additional connection (7), 1 of 8 pending slots used
rlm_sql_mysql: Starting connect to MySQL server
rlm_sql_mysql: Connected to database 'nodeny' on Localhost via UNIX 
socket, server version 5.6.39, protocol version 10
(1)     [sql] = ok
(1)     [exec] = noop
(1)   } # accounting = ok
(1) Sent Accounting-Response Id 248 from 127.0.0.1:1813 to 
127.0.0.1:54567 length 0
(1) Finished request
(1) Cleaning up request packet ID 248 with timestamp +78
Waking up in 4.9 seconds.

(0) Cleaning up request packet ID 253 with timestamp +77
Ready to process requests

[fet4]

У меня с freeradius 3 проблем нет.

У вас тоже вроде правильный лог но меня насторожило то что у вас NAS-Port-Type = Ethernet, а вы говорите что у вас pppoe, при тоннелях должно быть NAS-Port-Type = Virtual. Проверьте конфигурацию еще раз.

[kosmich]

У меня с freeradius 3 проблем нет.

Вы точно поняли что именно у меня происходит ? Если тип айпи "динамический", у меня "проблем" нет.

У вас тоже вроде правильный лог но меня насторожило то что у вас NAS-Port-Type = Ethernet, а вы говорите что у вас pppoe, при тоннелях должно быть NAS-Port-Type = Virtual. Проверьте конфигурацию еще раз.

Конфигурацию чего именно проверить ? Да, авторизация сейчас только PPPoE.
Почему с типом айпи "динамический" проблема не наблюдается ? нас-порт-тип тот же, лог успешной авторизации, без падения сесии через 10 секунд, в сообщении выше.
Сессия в обоих случаях поднимается. Но с типом айпи адреса "статический" падает через 10 секунд.

[Efendy]

Раз по логу радиуса нет никаких ошибок, могу предложить вариант сравнить ответы радиуса при статическом и динамическом ip

[fet4]

kosmich извиняюсь, ты был прав!

При статике у клиента, сессия дропается/подымается и так по кругу! Давайте разбираться!
Позже пришлю ответы радиуса при  статическом и динамическом ip

[fet4]

Ответы идентичны

это динамика

Код:

[2018-02-23 21:14:47]:  info: vlan108: send [RADIUS(1) Access-Request id=1 <User-Name "maxinet"> <NAS-Identifier "accel-ppp-bras1"> <NAS-IP-Address 172.19.0.12> <NAS-Port-Type Virtual> <Service-Type Framed-User> <Framed-Protocol PPP> <Calling-Station-Id "ec:08:6b:d9:96:e7"> <Called-Station-Id "00:1b:21:d0:16:5c"> <MS-CHAP-Challenge> <MS-CHAP2-Response>]
[2018-02-23 21:14:47]:  info: vlan108: recv [RADIUS(1) Access-Accept id=1 <Framed-IP-Address 10.194.0.212> <Framed-IP-Netmask 255.255.255.255> <Framed-Protocol PPP> <MS-CHAP2-Success> <MS-MPPE-Recv-Key> <MS-MPPE-Send-Key> <MS-MPPE-Encryption-Policy 1> <MS-MPPE-Encryption-Type 6>]

статика

Код:

[2018-02-23 21:12:50]:  info: vlan108: send [RADIUS(1) Access-Request id=1 <User-Name "maxinet"> <NAS-Identifier "accel-ppp-bras1"> <NAS-IP-Address 172.19.0.12> <NAS-Port-Type Virtual> <Service-Type Framed-User> <Framed-Protocol PPP> <Calling-Station-Id "ec:08:6b:d9:96:e7"> <Called-Station-Id "00:1b:21:d0:16:5c"> <MS-CHAP-Challenge> <MS-CHAP2-Response>]
[2018-02-23 21:12:50]:  info: vlan108: recv [RADIUS(1) Access-Accept id=1 <Framed-IP-Address 10.194.31.154> <Framed-IP-Netmask 255.255.255.255> <Framed-Protocol PPP> <MS-CHAP2-Success> <MS-MPPE-Recv-Key> <MS-MPPE-Send-Key> <MS-MPPE-Encryption-Policy 1> <MS-MPPE-Encryption-Type 6>]

И что же делать?

[Efendy]

У тебя тоже ошибка "RADIUS: rad_send_request for user 'ррр_test' failed: No valid RADIUS responses received"? Чтоб мы не искали ошибку kosmich по твоим логам.

Также ты привел один ответ, а может быть некорректным последующий. Ты сравнивал ответы радиуса в момент когда сессия дропается?

[fet4]

У тебя тоже ошибка "RADIUS: rad_send_request for user 'ррр_test' failed: No valid RADIUS responses received"? Чтоб мы не искали ошибку kosmich по твоим логам.

Нет такого не было все чисто.

Здесь вот полный лог с разрывом. Вроде ж как для радиуса непонятно какой Ip ответила база, статика или диниамика. А по факту статика не работает. что за хрень

Код:

[2018-02-23 22:43:08]:  info: vlan108: recv [PPPoE PADI ec:08:6b:d9:96:e7 => ff:ff:ff:ff:ff:ff sid=0000 <Service-Name > <Host-Uniq 000007e9>]
[2018-02-23 22:43:08]:  info: vlan108: send [PPPoE PADO 00:1b:21:d0:16:5c => ec:08:6b:d9:96:e7 sid=0000 <AC-Name fibernet-bras1> <Service-Name > <AC-Cookie a6ba67c815ee5b55246f76f5674c69aecdd98fa3890f9776> <Host-Uniq 000007e9>]
[2018-02-23 22:43:08]:  info: vlan108: recv [PPPoE PADR ec:08:6b:d9:96:e7 => 00:1b:21:d0:16:5c sid=0000 <Service-Name > <Host-Uniq 000007e9> <AC-Cookie a6ba67c815ee5b55246f76f5674c69aecdd98fa3890f9776>]
[2018-02-23 22:43:08]:  info: vlan108: send [PPPoE PADS 00:1b:21:d0:16:5c => ec:08:6b:d9:96:e7 sid=9180 <AC-Name fibernet-bras1> <Service-Name > <Host-Uniq 000007e9>]
[2018-02-23 22:43:11]:  info: vlan108: recv [MSCHAP-v2 Response id=1 <497679a216f9dc1ce4826d8c46b93cd4>, <d5e5e32d8e2d2784ffd6e35f44bb448e1931a7f04e66885c>, F=0, name="maxinet"]
[2018-02-23 22:43:11]:  info: vlan108: send [RADIUS(1) Access-Request id=1 <User-Name "maxinet"> <NAS-Identifier "accel-ppp-bras1"> <NAS-IP-Address 172.19.0.12> <NAS-Port-Type Virtual> <Service-Type Framed-User> <Framed-Protocol PPP> <Calling-Station-Id "ec:08:6b:d9:96:e7"> <Called-Station-Id "00:1b:21:d0:16:5c"> <MS-CHAP-Challenge> <MS-CHAP2-Response>]
[2018-02-23 22:43:12]:  info: vlan108: recv [RADIUS(1) Access-Accept id=1 <Framed-IP-Address 10.194.31.154> <Framed-IP-Netmask 255.255.255.255> <Framed-Protocol PPP> <MS-CHAP2-Success> <MS-MPPE-Recv-Key> <MS-MPPE-Send-Key> <MS-MPPE-Encryption-Policy 1> <MS-MPPE-Encryption-Type 6>]
[2018-02-23 22:43:12]:  info: ppp81: connect: ppp81 <--> pppoe(ec:08:6b:d9:96:e7)
[2018-02-23 22:43:12]: debug: ppp81: ppp connected
[2018-02-23 22:43:12]:  info: ppp81: send [MSCHAP-v2 Success id=1 "S=93355E2CD19DA5DDCD61F9D4B763885EDA50CD81 M=Authentication succeeded"]
[2018-02-23 22:43:12]: debug: ppp81: auth_layer_started
[2018-02-23 22:43:12]: debug: ppp81: ccp_layer_start
[2018-02-23 22:43:12]: debug: ppp81: ipcp_layer_start
[2018-02-23 22:43:12]:  info: ppp81: send [IPCP ConfReq id=1 <addr 10.194.0.2>]
[2018-02-23 22:43:12]: debug: ppp81: ipv6cp_layer_start
[2018-02-23 22:43:12]:  info: ppp81: maxinet: authentication succeeded
[2018-02-23 22:43:12]:  info: ppp81: recv [IPCP ConfReq id=1 <addr 0.0.0.0> <dns1 0.0.0.0> <dns2 0.0.0.0>]
[2018-02-23 22:43:12]:  info: ppp81: send [IPCP ConfNak id=1 <addr 10.194.31.154> <dns1 172.19.0.5> <dns2 8.8.8.8>]
[2018-02-23 22:43:12]:  info: ppp81: recv [IPCP ConfAck id=1 <addr 10.194.0.2>]
[2018-02-23 22:43:12]:  info: ppp81: recv [IPCP ConfReq id=2 <addr 10.194.31.154> <dns1 172.19.0.5> <dns2 8.8.8.8>]
[2018-02-23 22:43:12]:  info: ppp81: send [IPCP ConfAck id=2]
[2018-02-23 22:43:12]: debug: ppp81: ipcp_layer_started
[2018-02-23 22:43:12]:  info: ppp81: send [RADIUS(1) Accounting-Request id=1 <User-Name "maxinet"> <NAS-Identifier "accel-ppp-bras1"> <NAS-IP-Address 172.19.0.12> <NAS-Port 81> <NAS-Port-Id "ppp81"> <NAS-Port-Type Virtual> <Service-Type Framed-User> <Framed-Protocol PPP> <Calling-Station-Id "ec:08:6b:d9:96:e7"> <Called-Station-Id "00:1b:21:d0:16:5c"> <Acct-Status-Type Start> <Acct-Authentic RADIUS> <Acct-Session-Id "586929edd888dfa8"> <Acct-Session-Time 0> <Acct-Input-Octets 0> <Acct-Output-Octets 0> <Acct-Input-Packets 0> <Acct-Output-Packets 0> <Acct-Input-Gigawords 0> <Acct-Output-Gigawords 0> <Framed-IP-Address 10.194.31.154>]
[2018-02-23 22:45:12]:  info: ppp81: send [RADIUS(1) Accounting-Request id=1 <User-Name "maxinet"> <NAS-Identifier "accel-ppp-bras1"> <NAS-IP-Address 172.19.0.12> <NAS-Port 81> <NAS-Port-Id "ppp81"> <NAS-Port-Type Virtual> <Service-Type Framed-User> <Framed-Protocol PPP> <Calling-Station-Id "ec:08:6b:d9:96:e7"> <Called-Station-Id "00:1b:21:d0:16:5c"> <Acct-Status-Type Start> <Acct-Authentic RADIUS> <Acct-Session-Id "586929edd888dfa8"> <Acct-Session-Time 0> <Acct-Input-Octets 0> <Acct-Output-Octets 0> <Acct-Input-Packets 0> <Acct-Output-Packets 0> <Acct-Input-Gigawords 0> <Acct-Output-Gigawords 0> <Framed-IP-Address 10.194.31.154>]
[2018-02-23 22:46:08]:  info: ppp81: recv [LCP TermReq id=2]
[2018-02-23 22:46:08]:  info: ppp81: send [LCP TermAck id=2]
[2018-02-23 22:46:08]: debug: ppp81: terminate
[2018-02-23 22:46:08]: debug: ppp81: lcp_layer_finish
[2018-02-23 22:46:08]: debug: ppp81: auth_layer_finish
[2018-02-23 22:46:08]: debug: ppp81: auth_layer_finished
[2018-02-23 22:46:08]: debug: ppp81: ccp_layer_finish
[2018-02-23 22:46:08]: debug: ppp81: ccp_layer_finished
[2018-02-23 22:46:08]: debug: ppp81: ipcp_layer_finish
[2018-02-23 22:46:08]: debug: ppp81: ipcp_layer_finished
[2018-02-23 22:46:08]: debug: ppp81: ipv6cp_layer_finish
[2018-02-23 22:46:08]: debug: ppp81: ipv6cp_layer_finished
[2018-02-23 22:46:08]:  info: ppp81: send [RADIUS(1) Accounting-Request id=1 <User-Name "maxinet"> <NAS-Identifier "accel-ppp-bras1"> <NAS-IP-Address 172.19.0.12> <NAS-Port 81> <NAS-Port-Id "ppp81"> <NAS-Port-Type Virtual> <Service-Type Framed-User> <Framed-Protocol PPP> <Calling-Station-Id "ec:08:6b:d9:96:e7"> <Called-Station-Id "00:1b:21:d0:16:5c"> <Acct-Status-Type Stop> <Acct-Authentic RADIUS> <Acct-Session-Id "586929edd888dfa8"> <Acct-Session-Time 179> <Acct-Input-Octets 15880> <Acct-Output-Octets 54> <Acct-Input-Packets 194> <Acct-Output-Packets 3> <Acct-Input-Gigawords 0> <Acct-Output-Gigawords 0> <Framed-IP-Address 10.194.31.154> <Acct-Terminate-Cause User-Request>]
[2018-02-23 22:46:09]:  info: vlan108: recv [PPPoE PADT ec:08:6b:d9:96:e7 => 00:1b:21:d0:16:5c sid=9180 <Host-Uniq 000007e9> <AC-Cookie a6ba67c815ee5b55246f76f5674c69aecdd98fa3890f9776>]
[2018-02-23 22:46:09]: debug: ppp81: pppoe: ppp finished
[2018-02-23 22:46:09]: debug: ppp81: lcp_layer_free
[2018-02-23 22:46:09]: debug: ppp81: auth_layer_free
[2018-02-23 22:46:09]: debug: ppp81: ccp_layer_free
[2018-02-23 22:46:09]: debug: ppp81: ipcp_layer_free
[2018-02-23 22:46:09]: debug: ppp81: ipv6cp_layer_free
[2018-02-23 22:46:09]: debug: ppp81: ppp destablished
[2018-02-23 22:46:09]:  info: vlan108: send [PPPoE PADT 00:1b:21:d0:16:5c => ec:08:6b:d9:96:e7 sid=9180 <AC-Name fibernet-bras1> <Service-Name >]
[2018-02-23 22:46:09]:  info: ppp81: disconnected
[2018-02-23 22:46:23]:  info: vlan108: recv [PPPoE PADI ec:08:6b:d9:96:e7 => ff:ff:ff:ff:ff:ff sid=0000 <Service-Name > <Host-Uniq 00000906>]
[2018-02-23 22:46:23]:  info: vlan108: send [PPPoE PADO 00:1b:21:d0:16:5c => ec:08:6b:d9:96:e7 sid=0000 <AC-Name fibernet-bras1> <Service-Name > <AC-Cookie a6ba67c815ee5b55246f76f5674c69ae89223d35f1a2bf87> <Host-Uniq 00000906>]
[2018-02-23 22:46:23]:  info: vlan108: recv [PPPoE PADR ec:08:6b:d9:96:e7 => 00:1b:21:d0:16:5c sid=0000 <Service-Name > <Host-Uniq 00000906> <AC-Cookie a6ba67c815ee5b55246f76f5674c69ae89223d35f1a2bf87>]
[2018-02-23 22:46:23]:  info: vlan108: send [PPPoE PADS 00:1b:21:d0:16:5c => ec:08:6b:d9:96:e7 sid=9b00 <AC-Name fibernet-bras1> <Service-Name > <Host-Uniq 00000906>]
[2018-02-23 22:46:26]:  info: vlan108: recv [MSCHAP-v2 Response id=1 <cb6cc144b6c1404ccbecfba3d53d554f>, <b0824a12806e676d199cf6a30968159c17ab7b816869a>, F=0, name="maxinet"]
[2018-02-23 22:46:26]:  info: vlan108: send [RADIUS(1) Access-Request id=1 <User-Name "maxinet"> <NAS-Identifier "accel-ppp-bras1"> <NAS-IP-Address 172.19.0.12> <NAS-Port-Type Virtual> <Service-Type Framed-User> <Framed-Protocol PPP> <Calling-Station-Id "ec:08:6b:d9:96:e7"> <Called-Station-Id "00:1b:21:d0:16:5c"> <MS-CHAP-Challenge> <MS-CHAP2-Response>]
[2018-02-23 22:46:26]:  info: vlan108: recv [RADIUS(1) Access-Accept id=1 <Framed-IP-Address 10.194.31.154> <Framed-IP-Netmask 255.255.255.255> <Framed-Protocol PPP> <MS-CHAP2-Success> <MS-MPPE-Recv-Key> <MS-MPPE-Send-Key> <MS-MPPE-Encryption-Policy 1> <MS-MPPE-Encryption-Type 6>]
[2018-02-23 22:46:26]:  info: ppp81: connect: ppp81 <--> pppoe(ec:08:6b:d9:96:e7)
[2018-02-23 22:46:26]: debug: ppp81: ppp connected
[2018-02-23 22:46:26]:  info: ppp81: send [MSCHAP-v2 Success id=1 "S=051926628E72DD1212CC4791BAF6DA4EA0DA799A M=Authentication succeeded"]
[2018-02-23 22:46:26]: debug: ppp81: auth_layer_started
[2018-02-23 22:46:26]: debug: ppp81: ccp_layer_start
[2018-02-23 22:46:26]: debug: ppp81: ipcp_layer_start
[2018-02-23 22:46:26]:  info: ppp81: send [IPCP ConfReq id=1 <addr 10.194.0.2>]
[2018-02-23 22:46:26]: debug: ppp81: ipv6cp_layer_start
[2018-02-23 22:46:26]:  info: ppp81: maxinet: authentication succeeded
[2018-02-23 22:46:26]:  info: ppp81: recv [IPCP ConfReq id=1 <addr 0.0.0.0> <dns1 0.0.0.0> <dns2 0.0.0.0>]
[2018-02-23 22:46:26]:  info: ppp81: send [IPCP ConfNak id=1 <addr 10.194.31.154> <dns1 172.19.0.5> <dns2 8.8.8.8>]
[2018-02-23 22:46:26]:  info: ppp81: recv [IPCP ConfAck id=1 <addr 10.194.0.2>]
[2018-02-23 22:46:26]:  info: ppp81: recv [IPCP ConfReq id=2 <addr 10.194.31.154> <dns1 172.19.0.5> <dns2 8.8.8.8>]
[2018-02-23 22:46:26]:  info: ppp81: send [IPCP ConfAck id=2]
[2018-02-23 22:46:26]: debug: ppp81: ipcp_layer_started
[2018-02-23 22:46:26]:  info: ppp81: send [RADIUS(1) Accounting-Request id=1 <User-Name "maxinet"> <NAS-Identifier "accel-ppp-bras1"> <NAS-IP-Address 172.19.0.12> <NAS-Port 81> <NAS-Port-Id "ppp81"> <NAS-Port-Type Virtual> <Service-Type Framed-User> <Framed-Protocol PPP> <Calling-Station-Id "ec:08:6b:d9:96:e7"> <Called-Station-Id "00:1b:21:d0:16:5c"> <Acct-Status-Type Start> <Acct-Authentic RADIUS> <Acct-Session-Id "586929edd888dfce"> <Acct-Session-Time 0> <Acct-Input-Octets 0> <Acct-Output-Octets 0> <Acct-Input-Packets 0> <Acct-Output-Packets 0> <Acct-Input-Gigawords 0> <Acct-Output-Gigawords 0> <Framed-IP-Address 10.194.31.154>]

[fet4]

Исходя с логов с динамикой, когда static то не приходит ответ в момент interim update

Это динамика

Код:

[2018-02-23 23:19:49]:  info: ppp81: recv [RADIUS(1) Accounting-Response id=

Код:

[2018-02-23 23:19:39]:  info: vlan108: send [PPPoE PADT 00:1b:21:d0:16:5c => ec:08:6b:d9:96:e7 sid=ff00 <AC-Name fibernet-bras1> <Service-Name >]
[2018-02-23 23:19:39]:  info: ppp81: disconnected
[2018-02-23 23:19:46]:  info: vlan108: recv [PPPoE PADI ec:08:6b:d9:96:e7 => ff:ff:ff:ff:ff:ff sid=0000 <Service-Name > <Host-Uniq 000009fd>]
[2018-02-23 23:19:46]:  info: vlan108: send [PPPoE PADO 00:1b:21:d0:16:5c => ec:08:6b:d9:96:e7 sid=0000 <AC-Name fibernet-bras1> <Service-Name > <AC-Cookie a6ba67c815ee5b55246f76f5674c69aeeb3146d44748aeab> <Host-Uniq 000009fd>]
[2018-02-23 23:19:46]:  info: vlan108: recv [PPPoE PADR ec:08:6b:d9:96:e7 => 00:1b:21:d0:16:5c sid=0000 <Service-Name > <Host-Uniq 000009fd> <AC-Cookie a6ba67c815ee5b55246f76f5674c69aeeb3146d44748aeab>]
[2018-02-23 23:19:46]:  info: vlan108: send [PPPoE PADS 00:1b:21:d0:16:5c => ec:08:6b:d9:96:e7 sid=01c0 <AC-Name fibernet-bras1> <Service-Name > <Host-Uniq 000009fd>]
[2018-02-23 23:19:49]:  info: vlan108: recv [MSCHAP-v2 Response id=1 <cf3929592c94622f4b8b93d4195c10>, <fd5af7e13bce908e4dd7fa31fe1527fe60da21196f4c6ea>, F=0, name="maxinet"]
[2018-02-23 23:19:49]:  info: vlan108: send [RADIUS(1) Access-Request id=1 <User-Name "maxinet"> <NAS-Identifier "accel-ppp-bras1"> <NAS-IP-Address 172.19.0.12> <NAS-Port-Type Virtual> <Service-Type Framed-User> <Framed-Protocol PPP> <Calling-Station-Id "ec:08:6b:d9:96:e7"> <Called-Station-Id "00:1b:21:d0:16:5c"> <MS-CHAP-Challenge> <MS-CHAP2-Response>]
[2018-02-23 23:19:49]:  info: vlan108: recv [RADIUS(1) Access-Accept id=1 <Framed-IP-Address 10.194.11.51> <Framed-IP-Netmask 255.255.255.255> <Framed-Protocol PPP> <MS-CHAP2-Success> <MS-MPPE-Recv-Key> <MS-MPPE-Send-Key> <MS-MPPE-Encryption-Policy 1> <MS-MPPE-Encryption-Type 6>]
[2018-02-23 23:19:49]:  info: ppp81: connect: ppp81 <--> pppoe(ec:08:6b:d9:96:e7)
[2018-02-23 23:19:49]: debug: ppp81: ppp connected
[2018-02-23 23:19:49]:  info: ppp81: send [MSCHAP-v2 Success id=1 "S=8F41350BE390F0D90688B32A8A8DFF85EFDE58D4 M=Authentication succeeded"]
[2018-02-23 23:19:49]: debug: ppp81: auth_layer_started
[2018-02-23 23:19:49]: debug: ppp81: ccp_layer_start
[2018-02-23 23:19:49]: debug: ppp81: ipcp_layer_start
[2018-02-23 23:19:49]:  info: ppp81: send [IPCP ConfReq id=1 <addr 10.194.0.2>]
[2018-02-23 23:19:49]: debug: ppp81: ipv6cp_layer_start
[2018-02-23 23:19:49]:  info: ppp81: maxinet: authentication succeeded
[2018-02-23 23:19:49]:  info: ppp81: recv [IPCP ConfReq id=1 <addr 0.0.0.0> <dns1 0.0.0.0> <dns2 0.0.0.0>]
[2018-02-23 23:19:49]:  info: ppp81: send [IPCP ConfNak id=1 <addr 10.194.11.51> <dns1 172.19.0.5> <dns2 8.8.8.8>]
[2018-02-23 23:19:49]:  info: ppp81: recv [IPCP ConfAck id=1 <addr 10.194.0.2>]
[2018-02-23 23:19:49]:  info: ppp81: recv [IPCP ConfReq id=2 <addr 10.194.11.51> <dns1 172.19.0.5> <dns2 8.8.8.8>]
[2018-02-23 23:19:49]:  info: ppp81: send [IPCP ConfAck id=2]
[2018-02-23 23:19:49]: debug: ppp81: ipcp_layer_started
[2018-02-23 23:19:49]:  info: ppp81: send [RADIUS(1) Accounting-Request id=1 <User-Name "maxinet"> <NAS-Identifier "accel-ppp-bras1"> <NAS-IP-Address 172.19.0.12> <NAS-Port 81> <NAS-Port-Id "ppp81"> <NAS-Port-Type Virtual> <Service-Type Framed-User> <Framed-Protocol PPP> <Calling-Station-Id "ec:08:6b:d9:96:e7"> <Called-Station-Id "00:1b:21:d0:16:5c"> <Acct-Status-Type Start> <Acct-Authentic RADIUS> <Acct-Session-Id "586929edd888e19d"> <Acct-Session-Time 0> <Acct-Input-Octets 0> <Acct-Output-Octets 0> <Acct-Input-Packets 0> <Acct-Output-Packets 0> <Acct-Input-Gigawords 0> <Acct-Output-Gigawords 0> <Framed-IP-Address 10.194.11.51>]
[2018-02-23 23:19:49]:  info: ppp81: recv [RADIUS(1) Accounting-Response id=1]
[2018-02-23 23:19:49]: debug: ppp81: pppoe: ppp started
[2018-02-23 23:21:49]:  info: ppp81: send [RADIUS(1) Accounting-Request id=2 <User-Name "maxinet"> <NAS-Identifier "accel-ppp-bras1"> <NAS-IP-Address 172.19.0.12> <NAS-Port 81> <NAS-Port-Id "ppp81"> <NAS-Port-Type Virtual> <Service-Type Framed-User> <Framed-Protocol PPP> <Calling-Station-Id "ec:08:6b:d9:96:e7"> <Called-Station-Id "00:1b:21:d0:16:5c"> <Acct-Status-Type Alive> <Acct-Authentic RADIUS> <Acct-Session-Id "586929edd888e19d"> <Acct-Session-Time 123> <Acct-Input-Octets 41642> <Acct-Output-Octets 16094> <Acct-Input-Packets 103> <Acct-Output-Packets 76> <Acct-Input-Gigawords 0> <Acct-Output-Gigawords 0> <Framed-IP-Address 10.194.11.51>]
[2018-02-23 23:21:49]:  info: ppp81: recv [RADIUS(1) Accounting-Response id=2]
[2018-02-23 23:23:49]:  info: ppp81: send [RADIUS(1) Accounting-Request id=3 <User-Name "maxinet"> <NAS-Identifier "accel-ppp-bras1"> <NAS-IP-Address 172.19.0.12> <NAS-Port 81> <NAS-Port-Id "ppp81"> <NAS-Port-Type Virtual> <Service-Type Framed-User> <Framed-Protocol PPP> <Calling-Station-Id "ec:08:6b:d9:96:e7"> <Called-Station-Id "00:1b:21:d0:16:5c"> <Acct-Status-Type Alive> <Acct-Authentic RADIUS> <Acct-Session-Id "586929edd888e19d"> <Acct-Session-Time 243> <Acct-Input-Octets 55780> <Acct-Output-Octets 19439> <Acct-Input-Packets 170> <Acct-Output-Packets 93> <Acct-Input-Gigawords 0> <Acct-Output-Gigawords 0> <Framed-IP-Address 10.194.11.51>]
[2018-02-23 23:23:49]:  info: ppp81: recv [RADIUS(1) Accounting-Response id=3]
[2018-02-23 23:25:49]:  info: ppp81: send [RADIUS(1) Accounting-Request id=4 <User-Name "maxinet"> <NAS-Identifier "accel-ppp-bras1"> <NAS-IP-Address 172.19.0.12> <NAS-Port 81> <NAS-Port-Id "ppp81"> <NAS-Port-Type Virtual> <Service-Type Framed-User> <Framed-Protocol PPP> <Calling-Station-Id "ec:08:6b:d9:96:e7"> <Called-Station-Id "00:1b:21:d0:16:5c"> <Acct-Status-Type Alive> <Acct-Authentic RADIUS> <Acct-Session-Id "586929edd888e19d"> <Acct-Session-Time 363> <Acct-Input-Octets 58790> <Acct-Output-Octets 34210> <Acct-Input-Packets 204> <Acct-Output-Packets 130> <Acct-Input-Gigawords 0> <Acct-Output-Gigawords 0> <Framed-IP-Address 10.194.11.51>]
[2018-02-23 23:25:49]:  info: ppp81: recv [RADIUS(1) Accounting-Response id=4]
[2018-02-23 23:27:49]:  info: ppp81: send [RADIUS(1) Accounting-Request id=5 <User-Name "maxinet"> <NAS-Identifier "accel-ppp-bras1"> <NAS-IP-Address 172.19.0.12> <NAS-Port 81> <NAS-Port-Id "ppp81"> <NAS-Port-Type Virtual> <Service-Type Framed-User> <Framed-Protocol PPP> <Calling-Station-Id "ec:08:6b:d9:96:e7"> <Called-Station-Id "00:1b:21:d0:16:5c"> <Acct-Status-Type Alive> <Acct-Authentic RADIUS> <Acct-Session-Id "586929edd888e19d"> <Acct-Session-Time 483> <Acct-Input-Octets 96181> <Acct-Output-Octets 37226> <Acct-Input-Packets 450> <Acct-Output-Packets 141> <Acct-Input-Gigawords 0> <Acct-Output-Gigawords 0> <Framed-IP-Address 10.194.11.51>]
[2018-02-23 23:27:49]:  info: ppp81: recv [RADIUS(1) Accounting-Response id=5]

[fet4]

radupdate по статике обновляет 0 строк

[fet4]

При динамике

Код:

Ready to process requests
(3243) Received Accounting-Request Id 5 from 172.19.0.12:35457 to 172.19.0.12:1813 length 203
(3243)   User-Name = "novostep16"
(3243)   NAS-Identifier = "accel-ppp-bras1"
(3243)   NAS-IP-Address = 172.19.0.12
(3243)   NAS-Port = 136
(3243)   NAS-Port-Id = "ppp136"
(3243)   NAS-Port-Type = Virtual
(3243)   Service-Type = Framed-User
(3243)   Framed-Protocol = PPP
(3243)   Calling-Station-Id = "d8:50:e6:ae:63:a8"
(3243)   Called-Station-Id = "00:1b:21:d0:16:5c"
(3243)   Acct-Status-Type = Interim-Update
(3243)   Acct-Authentic = RADIUS
(3243)   Acct-Session-Id = "586929edd888e53d"
(3243)   Acct-Session-Time = 483
(3243)   Acct-Input-Octets = 20543488
(3243)   Acct-Output-Octets = 132665416
(3243)   Acct-Input-Packets = 108396
(3243)   Acct-Output-Packets = 142405
(3243)   Acct-Input-Gigawords = 0
(3243)   Acct-Output-Gigawords = 0
(3243)   Framed-IP-Address = 10.194.7.12
(3243) # Executing section accounting from file /etc/freeradius/3.0/sites-enabled/default
(3243)   accounting {
(3243)     if (&NAS-Port-Type == "Ethernet") {
(3243)     if (&NAS-Port-Type == "Ethernet")  -> FALSE
(3243)     elsif (&NAS-Port-Type == "Virtual") {
(3243)     elsif (&NAS-Port-Type == "Virtual")  -> TRUE
(3243)     elsif (&NAS-Port-Type == "Virtual")  {
(3243) sql_pppoe: EXPAND .query
(3243) sql_pppoe:    --> .query
(3243) sql_pppoe: Using query template 'query'
rlm_sql (sql_pppoe): Reserved connection (9)
(3243) sql_pppoe: EXPAND call radupdate_pppoe('%{User-Name}','%{Framed-IP-Address}','user=%{Calling-Station-Id};nas=%{NAS-IP-Address}','%{NAS-Identifier}','%{Acct-Session-Id}')
(3243) sql_pppoe:    --> call radupdate_pppoe('novostep16','10.194.7.12','user=d8:50:e6:ae:63:a8;nas=172.19.0.12','accel-ppp-bras1','586929edd888e53d')
(3243) sql_pppoe: Executing query: call radupdate_pppoe('novostep16','10.194.7.12','user=d8:50:e6:ae:63:a8;nas=172.19.0.12','accel-ppp-bras1','586929edd888e53d')
(3243) sql_pppoe: SQL query returned: success
(3243) sql_pppoe: 1 record(s) updated
rlm_sql (sql_pppoe): Released connection (9)
(3243)       [sql_pppoe] = ok
(3243)     } # elsif (&NAS-Port-Type == "Virtual")  = ok
(3243)   } # accounting = ok
(3243) Sent Accounting-Response Id 5 from 172.19.0.12:1813 to 172.19.0.12:35457 length 0
(3243) Finished request
(3243) Cleaning up request packet ID 5 with timestamp +576
Ready to process requests

[Efendy]

 Видимо в этом и проблема. Значит pppoe-сервер ожидает ответ на аккаунтинг. Кстати, это плюс ибо скорее всего в ответе можно будет послать атрибуты для изменения скорости или подобного без модуля coa. Покажи тогда процедуру radupdate_pppoe

[fet4]

Видимо в этом и проблема. Значит pppoe-сервер ожидает ответ на аккаунтинг. Кстати, это плюс ибо скорее всего в ответе можно будет послать атрибуты для изменения скорости или подобного без модуля coa. Покажи тогда процедуру radupdate_pppoe

Код:

DELIMITER $$
CREATE DEFINER=`nodeny`@`%` PROCEDURE `radupdate_pppoe`(IN login VARCHAR(64), IN ip VARCHAR(16), IN properties VARCHAR(255), IN `tag` VARCHAR(64), IN `ses` VARCHAR(64))
BEGIN
  DECLARE usr_id INT;
  DECLARE usr_ip VARCHAR(15) DEFAULT NULL;
  SELECT id INTO usr_id FROM users WHERE name=login LIMIT 1;
  SELECT get_ip_by_tag(usr_id, tag) INTO usr_ip;
  CALL set_auth(usr_ip, CONCAT('mod=pppoe;','ses=',ses,';',REPLACE(properties,':','')));
END$$
DELIMITER ;

Код:

DELIMITER $$
CREATE DEFINER=`nodeny`@`%` FUNCTION `get_ip_by_tag`( user_id INTEGER UNSIGNED, tag VARCHAR(64) ) RETURNS varchar(15) CHARSET utf8
    NO SQL
BEGIN
    DECLARE user_ip VARCHAR(15);
    DECLARE real_ip VARCHAR(15) DEFAULT 0;
    DECLARE row_cnt INTEGER;
    DECLARE ip_id INTEGER;
    DECLARE tries INTEGER DEFAULT 30;
    DECLARE id_min INTEGER;
    DECLARE id_max INTEGER;

    SELECT INET_NTOA(ip) INTO user_ip FROM ip_pool
        WHERE uid = user_id AND type='static' LIMIT 1;
    IF( user_ip IS NOT NULL ) THEN RETURN user_ip; END IF;

    SELECT 1 INTO real_ip FROM users_services WHERE uid = user_id AND tags LIKE '%,realip,%';

    SELECT id, INET_NTOA(ip) INTO ip_id, user_ip FROM ip_pool
        WHERE uid = user_id AND type = 'dynamic' AND realip = IF(real_ip>0,1,0)
            AND tags LIKE CONCAT('%,', tag, ',%')
        LIMIT 1;

    IF( ip_id IS NOT NULL) THEN
        UPDATE ip_pool SET `release` = UNIX_TIMESTAMP() + 3600
            WHERE id = ip_id AND uid = user_id;
        SELECT ROW_COUNT() INTO row_cnt;
        IF( row_cnt > 0 ) THEN RETURN user_ip; END IF;
    END IF;

    SELECT MAX(id), MIN(id) INTO id_max, id_min
        FROM ip_pool
        WHERE type = 'dynamic' AND realip = IF(real_ip>0,1,0)
            AND tags LIKE CONCAT('%,', tag, ',%');

    sel_ip: WHILE tries > 0 DO
        SELECT id, INET_NTOA(ip) INTO ip_id, user_ip
            FROM ip_pool
            WHERE uid = 0
                AND id >= (CEIL(RAND() * (id_max - id_min)) + id_min)
                AND id <= id_max
                LIMIT 1;
        IF( user_ip IS NOT NULL) THEN
            UPDATE ip_pool SET uid = user_id, `release` = UNIX_TIMESTAMP() + 3600
                WHERE id = ip_id AND uid = 0;
            SELECT ROW_COUNT() INTO row_cnt;
            IF( row_cnt > 0 ) THEN RETURN user_ip; END IF;
            SET tries = tries - 5;
        END IF;
        SET tries = tries - 1;
    END WHILE;

END$$
DELIMITER ;

Код:

DELIMITER $$
CREATE DEFINER=`nodeny`@`%` PROCEDURE `set_auth`(IN usr_ip VARCHAR(15), IN auth_properties VARCHAR(255))
BEGIN
  DECLARE usr_id INT;
  SELECT uid INTO usr_id FROM ip_pool WHERE INET_ATON(usr_ip) = ip LIMIT 1;

  IF( usr_id > 0 ) THEN

    INSERT INTO auth_now SET
        ip = usr_ip,
        properties = auth_properties,
        start = UNIX_TIMESTAMP(),
        last = UNIX_TIMESTAMP()
    ON DUPLICATE KEY UPDATE
        properties = IF(auth_properties!='',auth_properties,properties),
        last = UNIX_TIMESTAMP();

    UPDATE ip_pool SET `release` = UNIX_TIMESTAMP() + 3600
        WHERE ip = INET_ATON(usr_ip) AND type = 'dynamic' LIMIT 1;
  END IF;
END$$
DELIMITER ;

[Efendy]

Наверное во фрирадиусе что-то не договаривают. В общем последней вызывается set_auth. Для динамики она делает апдейт в базе чтобы обновить время освобождения ip. Это и есть сообщение, что обновлена 1 запись. Видимо на нее и ориентируется фрирадиус версии, бля, три. Для статики, ессно, никакие апдейты не делаются. Если радиусу нужно чтоб была одна запись, ну, давай попробуй после CALL set_auth(usr_ip, CONCAT('mod=pppoe;','ses=',ses,';',REPLACE(properties,':',''))); добавить код:

Код:

UPDATE users SET id=user_id WHERE id=user_id LIMIT 1;

P.S. Короче, посмотрел я в исходный код фрирадиуса, да там есть такая хуйня - оно смотрит на количество заапдейченных (или "заселекченных") записей и если 0 - возвращает ошибку. Походу можно просто

Код:

SELECT 1;

[fet4]

Дааа сука. Добавил

Код:

UPDATE users SET id=usr_id WHERE id=usr_id LIMIT 1;

и sql update query 1 и понеслась.

так может тогда проще

Код:

UPDATE ip_pool SET `release` = UNIX_TIMESTAMP() + 3600
        WHERE ip = INET_ATON(usr_ip) AND (type = 'dynamic' OR type = 'static') LIMIT 1;