Hi Alan and thanks, About last answer i will check it but the accounting on should response anything ? Thanks. -------- Mensaje original -------- De: Alan DeKok <aland@deployingradius.com> Fecha: 14/4/17 1:41 (GMT+01:00) Para: FreeRadius users mailing list <freeradius-users@lists.freeradius.org> Asunto: Re: Acct-Status-Type = 7 On Apr 13, 2017, at 5:56 PM, Oscar Jofre <oscar@jofre.com> wrote:
When I reboot a mikrotik with hotspot + radius activated, after reboot the router sends Acct-Status-Type = 7.
Which is "Accounting On". It's best to use names instead of numbers. They're more informative.
What I understand is that with this Acct-Status-Type = 7 the mikrotik tells radius that router has rebooted and then radius close all connections with NAS-Reboot.
Yes.
What happens in my case is that freeradius is not responding the Acct-Status-Type = 7 and then mikrotik thinks that and accumulate timeoute from raiuds.
Well, run the server in debugging mode to see what it's doing. As suggested in the FAQ, web pages, "man" pages, and daily on this list. Alan DeKok. - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
On Apr 14, 2017, at 6:50 AM, Oscar Jofre <oscar@jofre.com> wrote:
Hi Alan and thanks, About last answer i will check it but the accounting on should response anything ?
Yes. And again, if you read the debug log, you would see this. Alan DeKok.
Hi , I did several test. 1) I do Installed freeradius on a virtual machine on my computer. I run it with -X and without and this server is always responding to the Accounting ON. Using NTRadPing - Getting Responds Accounting on Usung Mikrotik - Getting Responds Accounting on 2) with my freeradius on Production is the same version of freeradius, same config files (except passwords) o got: Using NTRadPing - Getting Responds Accounting on Usung Mikrotik - NO Responding Accounting on * Mikrotik and NTRadPing are on the same LAN, switched on the same proxy. I did tried to learn on test radius how works raddebug but I can't filter requests. I'm trying to only see requests from a NAS or from a specific IP but always I get echo information with raddebug I tried WORKING raddebug -c '(Acct-Status-Type == Accounting-On)' I tried NOT WORKING raddebug -i 172.17.1.110 raddebug -c'(Packet-Src-IP-Address == 172.17.1.110)' raddebug -c '(NAS-IP-Address == 172.17.1.1100)' when I'm sending from another IP and always get info: example: [root@localhost radius]# raddebug -i 10.1.1.1 (19) Sun Apr 16 17:06:17 2017: Debug: <running>: Received Accounting-Request Id 79 from 172.17.1.116:55239 to 172.17.1.21:1813 length 66 (19) Sun Apr 16 17:06:17 2017: Debug: <running>: User-Name = "pru" (19) Sun Apr 16 17:06:17 2017: Debug: <running>: Acct-Status-Type = Accounting-On (19) Sun Apr 16 17:06:17 2017: Debug: <running>: Acct-Session-Id = "19408" (19) Sun Apr 16 17:06:17 2017: Debug: <running>: Acct-Status-Type = Accounting-On (19) Sun Apr 16 17:06:17 2017: Debug: <running>: Acct-Delay-Time = 0 (19) Sun Apr 16 17:06:17 2017: Debug: <running>: NAS-Identifier = "\"SERVER\"" (19) Sun Apr 16 17:06:17 2017: Debug: <running>: NAS-IP-Address = 172.16.5.240 (19) Sun Apr 16 17:06:17 2017: Debug: <running>: # Executing section preacct from file /etc/raddb/sites-enabled/default (19) Sun Apr 16 17:06:17 2017: Debug: <running>: preacct { (19) Sun Apr 16 17:06:17 2017: Debug: [preprocess] = ok (19) Sun Apr 16 17:06:17 2017: Debug: policy acct_unique { (19) Sun Apr 16 17:06:17 2017: Debug: if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) { (19) Sun Apr 16 17:06:17 2017: Debug: EXPAND %{string:Class} (19) Sun Apr 16 17:06:17 2017: Debug: --> (19) Sun Apr 16 17:06:17 2017: Debug: if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) -> FALSE (19) Sun Apr 16 17:06:17 2017: Debug: else { (19) Sun Apr 16 17:06:17 2017: Debug: update request { (19) Sun Apr 16 17:06:17 2017: Debug: EXPAND %{md5:%{User-Name},%{Acct-Session-ID},%{%{NAS-IPv6-Address}:-%{NAS-IP-Address}},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}} (19) Sun Apr 16 17:06:17 2017: Debug: --> e133e7b9f9041cad17523455aeaebb46 (19) Sun Apr 16 17:06:17 2017: Debug: } # update request = noop (19) Sun Apr 16 17:06:17 2017: Debug: } # else = noop (19) Sun Apr 16 17:06:17 2017: Debug: } # policy acct_unique = noop (19) Sun Apr 16 17:06:17 2017: Debug: suffix: Checking for suffix after "@" (19) Sun Apr 16 17:06:17 2017: Debug: suffix: No '@' in User-Name = "pru", looking up realm NULL (19) Sun Apr 16 17:06:17 2017: Debug: suffix: No such realm "NULL" (19) Sun Apr 16 17:06:17 2017: Debug: [suffix] = noop (19) Sun Apr 16 17:06:17 2017: Debug: [files] = noop (19) Sun Apr 16 17:06:17 2017: Debug: } # preacct = ok (19) Sun Apr 16 17:06:17 2017: Debug: # Executing section accounting from file /etc/raddb/sites-enabled/default (19) Sun Apr 16 17:06:17 2017: Debug: accounting { (19) Sun Apr 16 17:06:17 2017: Debug: detail: EXPAND /var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d (19) Sun Apr 16 17:06:17 2017: Debug: detail: --> /var/log/radius/radacct/172.17.1.116/detail-20170416 (19) Sun Apr 16 17:06:17 2017: Debug: 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-20170416 (19) Sun Apr 16 17:06:17 2017: Debug: detail: EXPAND %t (19) Sun Apr 16 17:06:17 2017: Debug: detail: --> Sun Apr 16 17:06:17 2017 (19) Sun Apr 16 17:06:17 2017: Debug: [detail] = ok (19) Sun Apr 16 17:06:17 2017: Debug: [unix] = noop (19) Sun Apr 16 17:06:17 2017: Debug: sql: EXPAND %{tolower:type.%{Acct-Status-Type}.query} (19) Sun Apr 16 17:06:17 2017: Debug: sql: --> type.accounting-on.query (19) Sun Apr 16 17:06:17 2017: Debug: sql: Using query template 'query' (19) Sun Apr 16 17:06:17 2017: Debug: sql: EXPAND %{User-Name} (19) Sun Apr 16 17:06:17 2017: Debug: sql: --> pru (19) Sun Apr 16 17:06:17 2017: Debug: sql: SQL-User-Name set to 'pru' (19) Sun Apr 16 17:06:17 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}) (19) Sun Apr 16 17:06:17 2017: Debug: sql: --> UPDATE radacct SET acctstoptime = FROM_UNIXTIME(1492355177), acctsessiontime = '1492355177' - UNIX_TIMESTAMP(acctstarttime), acctterminatecause = 'NAS-Reboot' WHERE acctstoptime IS NULL AND nasipaddress = '172.16.5.240' AND acctstarttime <= FROM_UNIXTIME(1492355177) (19) Sun Apr 16 17:06:17 2017: Debug: sql: Executing query: UPDATE radacct SET acctstoptime = FROM_UNIXTIME(1492355177), acctsessiontime = '1492355177' - UNIX_TIMESTAMP(acctstarttime), acctterminatecause = 'NAS-Reboot' WHERE acctstoptime IS NULL AND nasipaddress = '172.16.5.240' AND acctstarttime <= FROM_UNIXTIME(1492355177) (19) Sun Apr 16 17:06:17 2017: Debug: sql: SQL query returned: success (19) Sun Apr 16 17:06:17 2017: Debug: sql: 0 record(s) updated (19) Sun Apr 16 17:06:17 2017: Debug: sql: No additional queries configured (19) Sun Apr 16 17:06:17 2017: Debug: [sql] = noop (19) Sun Apr 16 17:06:17 2017: Debug: [exec] = noop (19) Sun Apr 16 17:06:17 2017: Debug: attr_filter.accounting_response: EXPAND %{User-Name} (19) Sun Apr 16 17:06:17 2017: Debug: attr_filter.accounting_response: --> pru (19) Sun Apr 16 17:06:17 2017: Debug: attr_filter.accounting_response: Matched entry DEFAULT at line 12 (19) Sun Apr 16 17:06:17 2017: Debug: [attr_filter.accounting_response] = updated (19) Sun Apr 16 17:06:17 2017: Debug: } # accounting = updated (19) Sun Apr 16 17:06:17 2017: Debug: Sent Accounting-Response Id 79 from 172.17.1.21:1813 to 172.17.1.116:55239 length 0 (19) Sun Apr 16 17:06:17 2017: Debug: Finished request (19) Sun Apr 16 17:06:17 2017: Debug: Cleaning up request packet ID 79 with timestamp +1581 -----Mensaje original----- De: Freeradius-Users [mailto:freeradius-users-bounces+oscar=jofre.com@lists.freeradius.org] En nombre de Alan DeKok Enviado el: viernes, 14 de abril de 2017 16:34 Para: FreeRadius users mailing list Asunto: Re: Acct-Status-Type = 7 On Apr 14, 2017, at 6:50 AM, Oscar Jofre <oscar@jofre.com> wrote:
Hi Alan and thanks, About last answer i will check it but the accounting on should response anything ?
Yes. And again, if you read the debug log, you would see this. Alan DeKok. - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
On Apr 16, 2017, at 11:13 AM, Oscar Jofre <oscar@jofre.com> wrote:
1) I do Installed freeradius on a virtual machine on my computer. I run it with -X and without and this server is always responding to the Accounting ON.
Then the server is working correctly.
2) with my freeradius on Production is the same version of freeradius, same config files (except passwords) o got: Using NTRadPing - Getting Responds Accounting on Usung Mikrotik - NO Responding Accounting on
Then read the debug log from that request.
I did tried to learn on test radius how works raddebug but I can't filter requests. I'm trying to only see requests from a NAS or from a specific IP but always I get echo information with raddebug
What is "echo information" ? You can also run radsniff, which will show the contents of the packets from Mikrotik. Then, take those attributes, and use then in radclient, to send packets to the server. And run the server in debug mode to see what's going on. Alan DeKok.
Hi, Now I think I Found the issue ... If the Accounting ON comes with USER informed then radius sends response but if the USER is empty then the radius is not responding. I did check with NTRadPing with user (a) and radius response and with user empty () then radius not responding. WITH NO USER: Not sending reply to client ... (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 = yy.yy.yy.yy (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: 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 WITH USER (test): Sent Accounting-Response .... (3138) Sun Apr 16 20:24:59 2017: Debug: <running>: Received Accounting-Request Id 5 from 88.13.35.213:51954 to 91.229.58.125:1813 length 72 (3138) Sun Apr 16 20:24:59 2017: Debug: <running>: User-Name = " test " (3138) Sun Apr 16 20:24:59 2017: Debug: <running>: Acct-Status-Type = Accounting-On (3138) Sun Apr 16 20:24:59 2017: Debug: <running>: Acct-Session-Id = "3500" (3138) Sun Apr 16 20:24:59 2017: Debug: <running>: NAS-IP-Address = yy.yy.yy.yy (3138) Sun Apr 16 20:24:59 2017: Debug: <running>: Acct-Status-Type = Accounting-On (3138) Sun Apr 16 20:24:59 2017: Debug: <running>: Acct-Delay-Time = 0 (3138) Sun Apr 16 20:24:59 2017: Debug: <running>: NAS-Identifier = "\"SERVER\"" (3138) Sun Apr 16 20:24:59 2017: Debug: <running>: # Executing section preacct from file /etc/raddb/sites-enabled/default (3138) Sun Apr 16 20:24:59 2017: Debug: <running>: preacct { .... (3138) Sun Apr 16 20:24:59 2017: Debug: sql: SQL query returned: success (3138) Sun Apr 16 20:24:59 2017: Debug: sql: 0 record(s) updated (3138) Sun Apr 16 20:24:59 2017: Debug: sql: No additional queries configured (3138) Sun Apr 16 20:24:59 2017: Debug: [sql] = noop (3138) Sun Apr 16 20:24:59 2017: Debug: [exec] = noop (3138) Sun Apr 16 20:24:59 2017: Debug: attr_filter.accounting_response: EXPAND %{User-Name} (3138) Sun Apr 16 20:24:59 2017: Debug: attr_filter.accounting_response: --> test (3138) Sun Apr 16 20:24:59 2017: Debug: attr_filter.accounting_response: Matched entry DEFAULT at line 12 (3138) Sun Apr 16 20:24:59 2017: Debug: [attr_filter.accounting_response] = updated (3138) Sun Apr 16 20:24:59 2017: Debug: } # accounting = updated (3138) Sun Apr 16 20:24:59 2017: Debug: Sent Accounting-Response Id 5 from xx.xx.xx.xx:1813 to yy.yy.yy.yy:51954 length 0 Is it correct that with no USER radius is not responding an Accounting-On ? Can I change this ? Thanks ! -----Mensaje original----- De: Freeradius-Users [mailto:freeradius-users-bounces+oscar=jofre.com@lists.freeradius.org] En nombre de Alan DeKok Enviado el: domingo, 16 de abril de 2017 19:28 Para: FreeRadius users mailing list Asunto: Re: Acct-Status-Type = 7 On Apr 16, 2017, at 11:13 AM, Oscar Jofre <oscar@jofre.com> wrote:
1) I do Installed freeradius on a virtual machine on my computer. I run it with -X and without and this server is always responding to the Accounting ON.
Then the server is working correctly.
2) with my freeradius on Production is the same version of freeradius, same config files (except passwords) o got: Using NTRadPing - Getting Responds Accounting on Usung Mikrotik - NO Responding Accounting on
Then read the debug log from that request.
I did tried to learn on test radius how works raddebug but I can't filter requests. I'm trying to only see requests from a NAS or from a specific IP but always I get echo information with raddebug
What is "echo information" ? You can also run radsniff, which will show the contents of the packets from Mikrotik. Then, take those attributes, and use then in radclient, to send packets to the server. And run the server in debug mode to see what's going on. Alan DeKok. - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
Hi, More info. 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. PRODUCTION NOT RESPONDING: (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 TEST YES RESPONDING (3) Sun Apr 16 21:46:27 2017: Debug: sql: SQL query returned: success (3) Sun Apr 16 21:46:27 2017: Debug: sql: 0 record(s) updated (3) Sun Apr 16 21:46:27 2017: Debug: sql: No additional queries configured (3) Sun Apr 16 21:46:27 2017: Debug: [sql] = noop (3) Sun Apr 16 21:46:27 2017: Debug: [exec] = noop (3) Sun Apr 16 21:46:27 2017: Debug: attr_filter.accounting_response: EXPAND %{User-Name} (3) Sun Apr 16 21:46:27 2017: Debug: attr_filter.accounting_response: --> (3) Sun Apr 16 21:46:27 2017: Debug: [attr_filter.accounting_response] = noop (3) Sun Apr 16 21:46:27 2017: Debug: } # accounting = ok (3) Sun Apr 16 21:46:27 2017: Debug: Sent Accounting-Response Id 13 from 172.17.1.21:1813 to 172.17.1.116:65068 length 0 (3) Sun Apr 16 21:46:27 2017: Debug: Finished request (3) Sun Apr 16 21:46:27 2017: Debug: Cleaning up request packet ID 13 with timestamp +37 The only place I see something about response is on /sites-enabled/default # # Accounting. Log the accounting data. # accounting { ... # if (noop) { # ok # } ... } But both are commented ... where I can see the differences ? Thanks ! -----Mensaje original----- De: Freeradius-Users [mailto:freeradius-users-bounces+oscar=jofre.com@lists.freeradius.org] En nombre de Oscar Jofre Enviado el: domingo, 16 de abril de 2017 20:42 Para: 'FreeRadius users mailing list' Asunto: RE: Acct-Status-Type = 7 Hi, Now I think I Found the issue ... If the Accounting ON comes with USER informed then radius sends response but if the USER is empty then the radius is not responding. I did check with NTRadPing with user (a) and radius response and with user empty () then radius not responding. WITH NO USER: Not sending reply to client ... (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 = yy.yy.yy.yy (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: 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 WITH USER (test): Sent Accounting-Response .... (3138) Sun Apr 16 20:24:59 2017: Debug: <running>: Received Accounting-Request Id 5 from 88.13.35.213:51954 to 91.229.58.125:1813 length 72 (3138) Sun Apr 16 20:24:59 2017: Debug: <running>: User-Name = " test " (3138) Sun Apr 16 20:24:59 2017: Debug: <running>: Acct-Status-Type = Accounting-On (3138) Sun Apr 16 20:24:59 2017: Debug: <running>: Acct-Session-Id = "3500" (3138) Sun Apr 16 20:24:59 2017: Debug: <running>: NAS-IP-Address = yy.yy.yy.yy (3138) Sun Apr 16 20:24:59 2017: Debug: <running>: Acct-Status-Type = Accounting-On (3138) Sun Apr 16 20:24:59 2017: Debug: <running>: Acct-Delay-Time = 0 (3138) Sun Apr 16 20:24:59 2017: Debug: <running>: NAS-Identifier = "\"SERVER\"" (3138) Sun Apr 16 20:24:59 2017: Debug: <running>: # Executing section preacct from file /etc/raddb/sites-enabled/default (3138) Sun Apr 16 20:24:59 2017: Debug: <running>: preacct { .... (3138) Sun Apr 16 20:24:59 2017: Debug: sql: SQL query returned: success (3138) Sun Apr 16 20:24:59 2017: Debug: sql: 0 record(s) updated (3138) Sun Apr 16 20:24:59 2017: Debug: sql: No additional queries configured (3138) Sun Apr 16 20:24:59 2017: Debug: [sql] = noop (3138) Sun Apr 16 20:24:59 2017: Debug: [exec] = noop (3138) Sun Apr 16 20:24:59 2017: Debug: attr_filter.accounting_response: EXPAND %{User-Name} (3138) Sun Apr 16 20:24:59 2017: Debug: attr_filter.accounting_response: --> test (3138) Sun Apr 16 20:24:59 2017: Debug: attr_filter.accounting_response: Matched entry DEFAULT at line 12 (3138) Sun Apr 16 20:24:59 2017: Debug: [attr_filter.accounting_response] = updated (3138) Sun Apr 16 20:24:59 2017: Debug: } # accounting = updated (3138) Sun Apr 16 20:24:59 2017: Debug: Sent Accounting-Response Id 5 from xx.xx.xx.xx:1813 to yy.yy.yy.yy:51954 length 0 Is it correct that with no USER radius is not responding an Accounting-On ? Can I change this ? Thanks ! -----Mensaje original----- De: Freeradius-Users [mailto:freeradius-users-bounces+oscar=jofre.com@lists.freeradius.org] En nombre de Alan DeKok Enviado el: domingo, 16 de abril de 2017 19:28 Para: FreeRadius users mailing list Asunto: Re: Acct-Status-Type = 7 On Apr 16, 2017, at 11:13 AM, Oscar Jofre <oscar@jofre.com> wrote:
1) I do Installed freeradius on a virtual machine on my computer. I run it with -X and without and this server is always responding to the Accounting ON.
Then the server is working correctly.
2) with my freeradius on Production is the same version of freeradius, same config files (except passwords) o got: Using NTRadPing - Getting Responds Accounting on Usung Mikrotik - NO Responding Accounting on
Then read the debug log from that request.
I did tried to learn on test radius how works raddebug but I can't filter requests. I'm trying to only see requests from a NAS or from a specific IP but always I get echo information with raddebug
What is "echo information" ? You can also run radsniff, which will show the contents of the packets from Mikrotik. Then, take those attributes, and use then in radclient, to send packets to the server. And run the server in debug mode to see what's going on. Alan DeKok. - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
On Apr 17, 2017, at 6:51 AM, Oscar Jofre <oscar@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.
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@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@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
On Apr 17, 2017, at 12:41 PM, Oscar Jofre <oscar@jofre.com> wrote:
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...\
The idea is simple: follow the instructions on this list. When I say to post the debug log, I mean for you to post all of it. All of the documentation makes this clear. When you post part of the debug log, you are making it difficult for us to help you.
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.
Then post the debug log and let *us* help. It's not hard.
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 ...
It doesn't need a User-Name attribute. The NAS is rebooting. There's no "user".
If you need any more detail please let me know and I will the all to give necessary informations.
That was enough. The short answer is to go to the file raddb/sites-enabled/default. In the "accounting" section after the "sql" module, add: if (noop) { ok } There should already be code like that in the file, but commented out.
I don’t understand about: It's in the FAQ, "man" pages, web pages, and pretty much daily on this list
When I say to post the debug log. It's mentioned EVERYWHERE in the documentation, and daily on this list. Alan DeKok.
You can run radiusd -X on each server until the Ready to process requests line and then diff the output. That will show any differences in config easily. Also check versions and build environment...Are they the same? alan On 17 Apr 2017 6:02 pm, "Alan DeKok" <aland@deployingradius.com> wrote:
On Apr 17, 2017, at 12:41 PM, Oscar Jofre <oscar@jofre.com> wrote:
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...\
The idea is simple: follow the instructions on this list.
When I say to post the debug log, I mean for you to post all of it. All of the documentation makes this clear. When you post part of the debug log, you are making it difficult for us to help you.
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.
Then post the debug log and let *us* help. It's not hard.
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 ...
It doesn't need a User-Name attribute. The NAS is rebooting. There's no "user".
If you need any more detail please let me know and I will the all to give necessary informations.
That was enough.
The short answer is to go to the file raddb/sites-enabled/default. In the "accounting" section after the "sql" module, add:
if (noop) { ok }
There should already be code like that in the file, but commented out.
I don’t understand about: It's in the FAQ, "man" pages, web pages, and pretty much daily on this list
When I say to post the debug log. It's mentioned EVERYWHERE in the documentation, and daily on this list.
Alan DeKok.
- List info/subscribe/unsubscribe? See http://www.freeradius.org/ list/users.html
participants (3)
-
Alan Buxey -
Alan DeKok -
Oscar Jofre