Acct-Status-Type = 7
Oscar Jofre
oscar at jofre.com
Mon Apr 17 18:41:06 CEST 2017
Hi Alan,
I wish no need to try for hours, but even I'm a developer I don't have the deep knowledge about radius and even linux environment ... can't know about everything...
I wish you to point me to the correct instructions, I've read many pages about radius debugging, I've tried, trust me, to figure out by myself ... but still with no understand where is the difference.
I really appreciate you help !
The packets should be exactly the same (no username in both requests and different result). I'm sure I missing something ...
Here are all DEBUG:
PRODUCTION ENVIRONMENT with no USER-Name Accouting-on request:
(3126) Sun Apr 16 20:24:56 2017: Debug: <running>: Received Accounting-Request Id 7 from XX.XX.XX.XX:45247 to xx.xx.xx.xx:1813 length 46
(3126) Sun Apr 16 20:24:56 2017: Debug: <running>: Acct-Status-Type = Accounting-On
(3126) Sun Apr 16 20:24:56 2017: Debug: <running>: NAS-Identifier = "SERVER"
(3126) Sun Apr 16 20:24:56 2017: Debug: <running>: Acct-Delay-Time = 0
(3126) Sun Apr 16 20:24:56 2017: Debug: <running>: NAS-IP-Address = 172.16.5.151
(3126) Sun Apr 16 20:24:56 2017: Debug: <running>: # Executing section preacct from file /etc/raddb/sites-enabled/default
(3126) Sun Apr 16 20:24:56 2017: Debug: <running>: preacct {
(3126) Sun Apr 16 20:24:56 2017: Debug: [preprocess] = ok
(3126) Sun Apr 16 20:24:56 2017: Debug: policy acct_unique {
(3126) Sun Apr 16 20:24:56 2017: Debug: if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) {
(3126) Sun Apr 16 20:24:56 2017: Debug: EXPAND %{string:Class}
(3126) Sun Apr 16 20:24:56 2017: Debug: -->
(3126) Sun Apr 16 20:24:56 2017: Debug: if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) -> FALSE
(3126) Sun Apr 16 20:24:56 2017: Debug: else {
(3126) Sun Apr 16 20:24:56 2017: Debug: update request {
(3126) Sun Apr 16 20:24:56 2017: Debug: EXPAND %{md5:%{User-Name},%{Acct-Session-ID},%{%{NAS-IPv6-Address}:-%{NAS-IP-Address}},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}}
(3126) Sun Apr 16 20:24:56 2017: Debug: --> 4a4a38f54ceb2b943e65ceccad61a6f3
(3126) Sun Apr 16 20:24:56 2017: Debug: } # update request = noop
(3126) Sun Apr 16 20:24:56 2017: Debug: } # else = noop
(3126) Sun Apr 16 20:24:56 2017: Debug: } # policy acct_unique = noop
(3126) Sun Apr 16 20:24:56 2017: Debug: [suffix] = noop
(3126) Sun Apr 16 20:24:56 2017: Debug: [files] = noop
(3126) Sun Apr 16 20:24:56 2017: Debug: } # preacct = ok
(3126) Sun Apr 16 20:24:56 2017: Debug: # Executing section accounting from file /etc/raddb/sites-enabled/default
(3126) Sun Apr 16 20:24:56 2017: Debug: accounting {
(3126) Sun Apr 16 20:24:56 2017: Debug: [unix] = noop
(3126) Sun Apr 16 20:24:56 2017: Debug: sql: EXPAND %{tolower:type.%{Acct-Status-Type}.query}
(3126) Sun Apr 16 20:24:56 2017: Debug: sql: --> type.accounting-on.query
(3126) Sun Apr 16 20:24:56 2017: Debug: sql: Using query template 'query'
(3126) Sun Apr 16 20:24:56 2017: Debug: sql: EXPAND %{User-Name}
(3126) Sun Apr 16 20:24:56 2017: Debug: sql: -->
(3126) Sun Apr 16 20:24:56 2017: Debug: sql: SQL-User-Name set to ''
(3126) Sun Apr 16 20:24:56 2017: Debug: sql: EXPAND UPDATE radacct SET acctstoptime = FROM_UNIXTIME(%{integer:Event-Timestamp}), acctsessiontime = '%{integer:Event-Timestamp}' - UNIX_TIMESTAMP(acctstarttime), acctterminatecause = '%{%{Acct-Terminate-Cause}:-NAS-Reboot}' WHERE acctstoptime IS NULL AND nasipaddress = '%{NAS-IP-Address}' AND acctstarttime <= FROM_UNIXTIME(%{integer:Event-Timestamp})
(3126) Sun Apr 16 20:24:56 2017: Debug: sql: --> UPDATE radacct SET acctstoptime = FROM_UNIXTIME(1492367096), acctsessiontime = '1492367096' - UNIX_TIMESTAMP(acctstarttime), acctterminatecause = 'NAS-Reboot' WHERE acctstoptime IS NULL AND nasipaddress = '172.16.5.151' AND acctstarttime <= FROM_UNIXTIME(1492367096)
(3126) Sun Apr 16 20:24:56 2017: Debug: sql: Executing query: UPDATE radacct SET acctstoptime = FROM_UNIXTIME(1492367096), acctsessiontime = '1492367096' - UNIX_TIMESTAMP(acctstarttime), acctterminatecause = 'NAS-Reboot' WHERE acctstoptime IS NULL AND nasipaddress = '172.16.5.151' AND acctstarttime <= FROM_UNIXTIME(1492367096)
(3126) Sun Apr 16 20:24:56 2017: Debug: sql: SQL query returned: success
(3126) Sun Apr 16 20:24:56 2017: Debug: sql: 0 record(s) updated
(3126) Sun Apr 16 20:24:56 2017: Debug: sql: No additional queries configured
(3126) Sun Apr 16 20:24:56 2017: Debug: [sql] = noop
(3126) Sun Apr 16 20:24:56 2017: Debug: [exec] = noop
(3126) Sun Apr 16 20:24:56 2017: Debug: attr_filter.accounting_response: EXPAND %{User-Name}
(3126) Sun Apr 16 20:24:56 2017: Debug: attr_filter.accounting_response: -->
(3126) Sun Apr 16 20:24:56 2017: Debug: [attr_filter.accounting_response] = noop
(3126) Sun Apr 16 20:24:56 2017: Debug: } # accounting = noop
(3126) Sun Apr 16 20:24:56 2017: Debug: Not sending reply to client.
(3126) Sun Apr 16 20:24:56 2017: Debug: Finished request
(3126) Sun Apr 16 20:24:56 2017: Debug: Cleaning up request packet ID 7 with timestamp +804
HERE TEST ENVIRONMENT SAME REQUEST RESPONDS OK
(6) Received Accounting-Request Id 38 from 172.17.1.116:53661 to 172.17.1.21:1813 length 54
(6) Acct-Status-Type = Accounting-On
(6) Acct-Session-Id = "3500"
(6) NAS-IP-Address = 172.16.5.240
(6) Acct-Delay-Time = 0
(6) NAS-Identifier = "\"SERVER\""
(6) # Executing section preacct from file /etc/raddb/sites-enabled/default
(6) preacct {
(6) [preprocess] = ok
(6) policy acct_unique {
(6) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) {
(6) EXPAND %{string:Class}
(6) -->
(6) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) -> FALSE
(6) else {
(6) update request {
(6) EXPAND %{md5:%{User-Name},%{Acct-Session-ID},%{%{NAS-IPv6-Address}:-%{NAS-IP-Address}},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}}
(6) --> 16e628259020c46d4b100e8258c6a5b1
(6) &Acct-Unique-Session-Id := 16e628259020c46d4b100e8258c6a5b1
(6) } # update request = noop
(6) } # else = noop
(6) } # policy acct_unique = noop
(6) [suffix] = noop
(6) [files] = noop
(6) } # preacct = ok
(6) # Executing section accounting from file /etc/raddb/sites-enabled/default
(6) accounting {
(6) detail: EXPAND /var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d
(6) detail: --> /var/log/radius/radacct/172.17.1.116/detail-20170417
(6) detail: /var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d expands to /var/log/radius/radacct/172.17.1.116/detail-20170417
(6) detail: EXPAND %t
(6) detail: --> Mon Apr 17 18:36:41 2017
(6) [detail] = ok
(6) [unix] = noop
(6) sql: EXPAND %{tolower:type.%{Acct-Status-Type}.query}
(6) sql: --> type.accounting-on.query
(6) sql: Using query template 'query'
rlm_sql (sql): Reserved connection (11)
(6) sql: EXPAND %{User-Name}
(6) sql: -->
(6) sql: SQL-User-Name set to ''
(6) sql: EXPAND UPDATE radacct SET acctstoptime = FROM_UNIXTIME(%{integer:Event-Timestamp}), acctsessiontime = '%{integer:Event-Timestamp}' - UNIX_TIMESTAMP(acctstarttime), acctterminatecause = '%{%{Acct-Terminate-Cause}:-NAS-Reboot}' WHERE acctstoptime IS NULL AND nasipaddress = '%{NAS-IP-Address}' AND acctstarttime <= FROM_UNIXTIME(%{integer:Event-Timestamp})
(6) sql: --> UPDATE radacct SET acctstoptime = FROM_UNIXTIME(1492447001), acctsessiontime = '1492447001' - UNIX_TIMESTAMP(acctstarttime), acctterminatecause = 'NAS-Reboot' WHERE acctstoptime IS NULL AND nasipaddress = '172.16.5.240' AND acctstarttime <= FROM_UNIXTIME(1492447001)
(6) sql: Executing query: UPDATE radacct SET acctstoptime = FROM_UNIXTIME(1492447001), acctsessiontime = '1492447001' - UNIX_TIMESTAMP(acctstarttime), acctterminatecause = 'NAS-Reboot' WHERE acctstoptime IS NULL AND nasipaddress = '172.16.5.240' AND acctstarttime <= FROM_UNIXTIME(1492447001)
rlm_sql_mysql: Rows matched: 0 Changed: 0 Warnings: 0
(6) sql: SQL query returned: success
(6) sql: 0 record(s) updated
(6) sql: No additional queries configured
rlm_sql (sql): Released connection (11)
(6) [sql] = noop
(6) [exec] = noop
(6) attr_filter.accounting_response: EXPAND %{User-Name}
(6) attr_filter.accounting_response: -->
(6) [attr_filter.accounting_response] = noop
(6) } # accounting = ok
(6) Sent Accounting-Response Id 38 from 172.17.1.21:1813 to 172.17.1.116:53661 length 0
(6) Finished request
(6) Cleaning up request packet ID 38 with timestamp +342
If you need any more detail please let me know and I will the all to give necessary informations.
I don’t understand about: It's in the FAQ, "man" pages, web pages, and pretty much daily on this list
Thanks a lot !
-----Mensaje original-----
De: Freeradius-Users [mailto:freeradius-users-bounces+oscar=jofre.com at lists.freeradius.org] En nombre de Alan DeKok
Enviado el: lunes, 17 de abril de 2017 13:50
Para: FreeRadius users mailing list
Asunto: Re: Acct-Status-Type = 7
On Apr 17, 2017, at 6:51 AM, Oscar Jofre <oscar at jofre.com> wrote:
> I've been trying for hours but can't find the differences between freeradius on my test environment where with empty user Accounting-on is responding and freeradius on production where Accounting-on with empty user is not responding.
There is no need to try for hours. There IS a need to follow instructions.
Post the debug output for the failure case. ALL OF IT.
I mean POST ALL OF THE DEBUG OUTPUT TO THE LIST.
The important differences between the two cases is the attributes in the packet. You're editing the debug output to REMOVE THE USEFUL INFORMATION. Which makes it impossible for us to help you.
Honestly, this shouldn't be difficult to understand. It's in the FAQ, "man" pages, web pages, and pretty much daily on this list. The only reason to post edited debug outputs is if you're refusing to follow any instructions.
Alan DeKok.
-
List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
More information about the Freeradius-Users
mailing list