acct_unique problem

Viana freeradius at radius.net.br
Mon Feb 8 22:03:19 CET 2016


Back to version 3.0.9 (I'm over 18 hours testing) I changed policy.d/accouting:
was: 
update request {
           &Acct-Unique-Session-Id := "%{md5:%{User-Name},%{Acct-Session-ID},%{%{NAS-IPv6-Address}:-%{NAS-IP-Address}},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}}"
            
         }

changed to:

update request {            
            &Acct-Unique-Session-Id := "%{md5:%{User-Name},%{Acct-Session-ID},%{NAS-IP-Address}}"

         }

So I simulated the problem again and radacct worked FINE: it did NOT create a new line (because uniqueid was the same!) and put the ACCTSTOPTIME as expected.

But ANOTHER PROBLEM OCCURRED: radipppol was NOT updated! 

Inside sqlippool.conf I have: pool_key = "%{NAS-Port}"

So the pool_key is Nas-Port, ok!

Let´s see the query:

(0) sqlippool_v4: EXPAND %{User-Name}
(0) sqlippool_v4:    --> test
(0) sqlippool_v4: SQL-User-Name set to 'test'
(0) sqlippool_v4: EXPAND START TRANSACTION
(0) sqlippool_v4:    --> START TRANSACTION
(0) sqlippool_v4: Executing query: START TRANSACTION
(0) sqlippool_v4: 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}'
(0) sqlippool_v4:    --> UPDATE radippool SET nasipaddress = '', pool_key = 0, callingstationid = '', username = '', expiry_time = NULL WHERE nasipaddress = '192.168.0.1' AND pool_key = '0' AND username = 'test' AND callingstationid = '' AND framedipaddress = '1.1.1.1'
(0) sqlippool_v4: Executing query: UPDATE radippool SET nasipaddress = '', pool_key = 0, callingstationid = '', username = '', expiry_time = NULL WHERE nasipaddress = '192.168.0.1' AND pool_key = '0' AND username = 'test' AND callingstationid = '' AND framedipaddress = '1.1.1.1'
rlm_sql_mysql: Rows matched: 0  Changed: 0  Warnings: 0
(0) sqlippool_v4: EXPAND COMMIT
(0) sqlippool_v4:    --> COMMIT
(0) sqlippool_v4: Executing query: COMMIT
(0) sqlippool_v4: EXPAND Released IP %{Framed-IP-Address} (did %{Called-Station-Id} cli %{Calling-Station-Id} user %{User-Name})
(0) sqlippool_v4:    --> Released IP 1.1.1.1 (did  cli  user test)
rlm_sql (sql): Released connection (0)
(0)     [sqlippool_v4] = ok


pool_key should not be ZERO!

Here is my conclusion:

When a user tries to connect there is a simultaneous check:

(0) sql: EXPAND SELECT COUNT(*) FROM radacct WHERE username = '%{SQL-User-Name}' AND acctstoptime IS NULL

When there is NO other connections (99% of the time), everything works fine.

But when this query returns a connection, Freeradius looses NAS-Identifier, NAS-Port-ID and NAS-Port, so It cannot close radacct and radipool. This is NOT behavior of version 2.1.12!

2.1.12 and 3.0.9 have the SAME behavior: close radacct and free the IP from radippool. But, because there is no NAS-Identifier, NAS-Port-ID and NAS-Port  the UPDATE queries does nothing.

When sites sites-enabled/default/preacct is called from a accounting-request, it works fine. But when is called in a access-request, after the simultaneous check, it did not get the NAS-Identifier, NAS-Port-ID and NAS-Port  parameters. Look this log (I put some asterisks at the beginning of the important lines):

(0) Received Access-Request Id 222 from 192.168.0.1:49006 to 192.168.0.99:1812 length 144
(0)   Service-Type = Framed-User
(0)   Framed-Protocol = PPP
(0)   NAS-Port = 15729440
(0)   NAS-Port-Type = Ethernet
(0)   User-Name = "test"
(0)   Calling-Station-Id = "C0:4A:00:87:C6:D9"
(0)   Called-Station-Id = "service1"
(0)   NAS-Port-Id = "bridge1"
(0)   CHAP-Challenge = 0x01cb327edb3e8c32494b0b6e6c10b09d
(0)   CHAP-Password = 0x01b3833103457a7f1707baa01e0c6dfa28
(0)   NAS-Identifier = "Main_Router"
(0)   NAS-IP-Address = 192.168.0.1
(0) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default
(0)   authorize {
(0)     policy filter_username {
(0)       if (!&User-Name) {
(0)       if (!&User-Name)  -> FALSE
(0)       if (&User-Name =~ / /) {
(0)       if (&User-Name =~ / /)  -> FALSE
(0)       if (&User-Name =~ /@.*@/ ) {
(0)       if (&User-Name =~ /@.*@/ )  -> FALSE
(0)       if (&User-Name =~ /\.\./ ) {
(0)       if (&User-Name =~ /\.\./ )  -> FALSE
(0)       if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/))  {
(0)       if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/))   -> FALSE
(0)       if (&User-Name =~ /\.$/)  {
(0)       if (&User-Name =~ /\.$/)   -> FALSE
(0)       if (&User-Name =~ /@\./)  {
(0)       if (&User-Name =~ /@\./)   -> FALSE
(0)     } # policy filter_username = notfound
(0)     [preprocess] = ok
(0) chap:   &control:Auth-Type := CHAP
(0)     [chap] = ok
(0)     [mschap] = noop
(0)     [digest] = noop
(0) suffix: Checking for suffix after "@"
(0) suffix: No '@' in User-Name = "test", looking up realm NULL
(0) suffix: No such realm "NULL"
(0)     [suffix] = noop
(0) eap: No EAP-Message, not doing EAP
(0)     [eap] = noop
(0) files: users: Matched entry DEFAULT at line 182
(0)     [files] = ok
(0) sql: EXPAND %{User-Name}
(0) sql:    --> test
(0) sql: SQL-User-Name set to 'test'
rlm_sql (sql): Reserved connection (1)
(0) sql: EXPAND SELECT id, username, attribute, value, op FROM radcheck WHERE username = '%{SQL-User-Name}' ORDER BY id
(0) sql:    --> SELECT id, username, attribute, value, op FROM radcheck WHERE username = 'test' ORDER BY id
(0) sql: Executing select query: SELECT id, username, attribute, value, op FROM radcheck WHERE username = 'test' ORDER BY id
(0) sql: User found in radcheck table
(0) sql: Conditional check items matched, merging assignment check items
(0) sql:   Cleartext-Password := "123456"
(0) sql: EXPAND SELECT id, username, attribute, value, op FROM radreply WHERE username = '%{SQL-User-Name}' ORDER BY id
(0) sql:    --> SELECT id, username, attribute, value, op FROM radreply WHERE username = 'test' ORDER BY id
(0) sql: Executing select query: SELECT id, username, attribute, value, op FROM radreply WHERE username = 'test' ORDER BY id
(0) sql: EXPAND SELECT groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority
(0) sql:    --> SELECT groupname FROM radusergroup WHERE username = 'test' ORDER BY priority
(0) sql: Executing select query: SELECT groupname FROM radusergroup WHERE username = 'test' ORDER BY priority
(0) sql: User found in the group table
(0) sql: EXPAND SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = '%{SQL-Group}' ORDER BY id
(0) sql:    --> SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = '10' ORDER BY id
(0) sql: Executing select query: SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = '10' ORDER BY id
(0) sql: Group "10": Conditional check items matched
(0) sql: Group "10": Merging assignment check items
(0) sql:   Simultaneous-Use := 1
(0) sql:   Pool-Name := "pool_ativo"
(0) sql: EXPAND SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = '%{SQL-Group}' ORDER BY id
(0) sql:    --> SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = '10' ORDER BY id
(0) sql: Executing select query: SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = '10' ORDER BY id
(0) sql: Group "10": Merging reply items
(0) sql:   Mikrotik-Delegated-IPv6-Pool := "PD"
rlm_sql (sql): Released connection (1)
rlm_sql (sql): 0 of 6 connections in use.  Need more spares
rlm_sql (sql): Opening additional connection (6), 1 of 26 pending slots used
rlm_sql_mysql: Starting connect to MySQL server
rlm_sql_mysql: Connected to database 'radius' on Localhost via UNIX socket, server version 5.6.25, protocol version 10
(0)     [sql] = ok
(0)     [expiration] = noop
(0)     [logintime] = noop
(0) pap: WARNING: Auth-Type already set.  Not setting to PAP
(0)     [pap] = noop
(0)   } # authorize = ok
(0) Found Auth-Type = CHAP
(0) # Executing group from file /usr/local/etc/raddb/sites-enabled/default
(0)   Auth-Type CHAP {
(0) chap: Comparing with "known good" Cleartext-Password
(0) chap: CHAP user "test" authenticated successfully
(0)     [chap] = ok
(0)   } # Auth-Type CHAP = ok
(0) # Executing section session from file /usr/local/etc/raddb/sites-enabled/default
*** (0)   session {
*** (0)     EXPAND %{NAS-Port}
*** (0)        --> 15729440
(0) sql: EXPAND %{User-Name}
(0) sql:    --> test
(0) sql: SQL-User-Name set to 'test'
(0) sql: EXPAND SELECT COUNT(*) FROM radacct WHERE username = '%{SQL-User-Name}' AND acctstoptime IS NULL
(0) sql:    --> SELECT COUNT(*) FROM radacct WHERE username = 'test' AND acctstoptime IS NULL
rlm_sql (sql): Reserved connection (2)
(0) sql: Executing select query: SELECT COUNT(*) FROM radacct WHERE username = 'test' AND acctstoptime IS NULL
(0) sql: EXPAND SELECT radacctid, acctsessionid, username, nasipaddress, nasportid, framedipaddress, callingstationid, framedprotocol FROM radacct WHERE username = '%{SQL-User-Name}' AND acctstoptime IS NULL
(0) sql:    --> SELECT radacctid, acctsessionid, username, nasipaddress, nasportid, framedipaddress, callingstationid, framedprotocol FROM radacct WHERE username = 'test' AND acctstoptime IS NULL
(0) sql: Executing select query: SELECT radacctid, acctsessionid, username, nasipaddress, nasportid, framedipaddress, callingstationid, framedprotocol FROM radacct WHERE username = 'test' AND acctstoptime IS NULL
(0) # Executing section preacct from file /usr/local/etc/raddb/sites-enabled/default
*** (0)   preacct {
*** (0)     EXPAND %{NAS-Port}
*** (0)        --> 0
(0)     [preprocess] = ok
(0)     policy acct_unique {
(0)       if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) {
(0)       EXPAND %{string:Class}
(0)          -->
(0)       if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i)  -> FALSE
(0)       else {
(0)         update request {
(0)           EXPAND %{md5:%{User-Name},%{Acct-Session-ID},%{NAS-IP-Address}}
(0)              --> ff97493ea4bc763492c5bd1544f13823
(0)           &Acct-Unique-Session-Id := ff97493ea4bc763492c5bd1544f13823
(0)         } # update request = noop
(0)         EXPAND %{User-Name}
(0)            --> test
(0)         EXPAND %{Acct-Session-ID}
(0)            --> 819000e3
(0)         EXPAND %{NAS-IPv6-Address}
(0)            -->
(0)         EXPAND %{NAS-IP-Address}
(0)            --> 192.168.0.1
(0)         EXPAND %{NAS-Identifier}
(0)            -->
(0)         EXPAND %{NAS-Port-ID}
(0)            -->
(0)         EXPAND %{NAS-Port}
(0)            --> 0
(0)       } # else = noop
(0)     } # policy acct_unique = noop


Nas-Port is ok in session, but zero in preacct:

(0)   session {
(0)     EXPAND %{NAS-Port}
(0)        --> 15729440 
(0) sql: EXPAND %{User-Name}
(0) sql:    --> test
(0) sql: SQL-User-Name set to 'test'
(0) sql: EXPAND SELECT COUNT(*) FROM radacct WHERE username = '%{SQL-User-Name}' AND acctstoptime IS NULL
(0) sql:    --> SELECT COUNT(*) FROM radacct WHERE username = 'test' AND acctstoptime IS NULL
rlm_sql (sql): Reserved connection (2)
(0) sql: Executing select query: SELECT COUNT(*) FROM radacct WHERE username = 'test' AND acctstoptime IS NULL
(0) sql: EXPAND SELECT radacctid, acctsessionid, username, nasipaddress, nasportid, framedipaddress, callingstationid, framedprotocol FROM radacct WHERE username = '%{SQL-User-Name}' AND acctstoptime IS NULL
(0) sql:    --> SELECT radacctid, acctsessionid, username, nasipaddress, nasportid, framedipaddress, callingstationid, framedprotocol FROM radacct WHERE username = 'test' AND acctstoptime IS NULL
(0) sql: Executing select query: SELECT radacctid, acctsessionid, username, nasipaddress, nasportid, framedipaddress, callingstationid, framedprotocol FROM radacct WHERE username = 'test' AND acctstoptime IS NULL
(0) # Executing section preacct from file /usr/local/etc/raddb/sites-enabled/default
(0)   preacct {
(0)     EXPAND %{NAS-Port}
(0)        --> 0 



Alan, thanks for your reply! You said that Access-Request should not go to preacct section. I looked into version 2:

[sql]   expand: SELECT radacctid, acctsessionid, username,                                nasipaddress, nasportid, framedipaddress,                                callingstationid, framedprotocol                                FROM radacct                                WHERE username = '%{SQL-User-Name}'                                AND acctstoptime IS NULL -> SELECT radacctid, acctsessionid, username,                                nasipaddress, nasportid, framedipaddress,                                callingstationid, framedprotocol                                FROM radacct                                WHERE username = 'test'                                AND acctstoptime IS NULL
# Executing section preacct from file /usr/local/etc/raddb/sites-enabled/default
+- entering group preacct {...}
++[preprocess] returns ok
[acct_unique] Hashing 'NAS-Port = 15729406,Client-IP-Address = 192.168.0.1,NAS-IP-Address = 192.168.0.1,Acct-Session-Id = "819000c2",User-Name = "test"'
[acct_unique] Acct-Unique-Session-ID = "5cc3e8235801dd84".
++[acct_unique] returns ok

It seems that after a positive “simultaneous check” FreeRadius go to preacct to close the old connection. Nas-Port value was passed to preacct in version 2.1.12.

Well, that´s It, looking for help... 

Regards
Fabricio

---
Este email foi escaneado pelo Avast antivírus.
http://www.avast.com


More information about the Freeradius-Users mailing list