Enc: Freeradius doesn't record acct-stop-time.
Hi Fajar, I Couldn't solve the problem yet... but I ran the Radius in debug mode, and I tried to disconnect my connection to see what are happening, as I couldn't find, I'll post it here. Thanks for the help. rad_recv: Accounting-Request packet from host XXX.XX.X.XXX:37121, id=232, length=268 Service-Type = Framed-User Framed-Protocol = PPP NAS-Port = 115296 NAS-Port-Type = Ethernet User-Name = "email@domain.com.br" Calling-Station-Id = "00:15:6D:E6:94:DB" Called-Station-Id = "pppoe-wip2" NAS-Port-Id = "WIP2" MS-CHAP-Domain = "domain.com.br" Acct-Session-Id = "81514b64" Framed-IP-Address = xxx.xx.X.XX Acct-Authentic = RADIUS Event-Timestamp = "Feb 17 2012 13:44:23 BRST" Acct-Session-Time = 79376 Acct-Input-Octets = 158226957 Acct-Input-Gigawords = 0 Acct-Input-Packets = 1112930 Acct-Output-Octets = 854637707 Acct-Output-Gigawords = 0 Acct-Output-Packets = 1115931 Acct-Status-Type = Stop Acct-Terminate-Cause = NAS-Request NAS-Identifier = "PPPoE-AND WIP2" Acct-Delay-Time = 0 Mikrotik-Realm = "domain.com.br" NAS-IP-Address = xxx.xx.x.xx Processing the preacct section of radiusd.conf modcall: entering group preacct for request 43 modcall[preacct]: module "preprocess" returns noop for request 43 rlm_acct_unique: Hashing 'NAS-Port = 115296,Client-IP-Address = xxx.xx.x.xx,NAS-IP-Address = xxx.xx.x.xxx,Acct-Session-Id = "81514b64",User-Name = "email@domain.com.br"' rlm_acct_unique: Acct-Unique-Session-ID = "4bc00ddcf558a324". modcall[preacct]: module "acct_unique" returns ok for request 43 rlm_realm: Looking up realm "domain.com.br" for User-Name = "email@domain.com.br" rlm_realm: No such realm "domain.com.br" modcall[preacct]: module "suffix" returns noop for request 43 modcall[preacct]: module "files" returns noop for request 43 modcall: leaving group preacct (returns ok) for request 43 Processing the accounting section of radiusd.conf modcall: entering group accounting for request 43 radius_xlat: '/var/log/radacct/xxx.xx.x.xx/detail-20120217' rlm_detail: /var/log/radacct/%{Client-IP-Address}/detail-%Y%m%d expands to /var/log/radacct/xxx.xx.x.xx/detail-20120217 modcall[accounting]: module "detail" returns ok for request 43 modcall[accounting]: module "unix" returns fail for request 43 modcall: leaving group accounting (returns fail) for request 43 Finished request 43 Going to the next request And the sqltrace, the only information with acct-stop-time is this: UPDATE radacct SET AcctStopTime='2012-02-10 17:43:19', AcctSessionTime=unix_timestamp('2012-02-10 17:43:19') - unix_timestamp(AcctStartTime), AcctTerminateCause='', AcctStopDelay = '0' WHERE AcctSessionTime=0 AND AcctStopTime=0 AND NASIPAddress= 'xxx.xx.x.xx' AND AcctStartTime <= '2012-02-10 17:43:19'; both were not collected from the same time. ________________________________ De: Fajar A. Nugraha <list@fajar.net> Para: Rodrigo Yoshioka <ro_yoshioka2002@yahoo.com.br>; FreeRadius users mailing list <freeradius-users@lists.freeradius.org> Enviadas: Terça-feira, 7 de Fevereiro de 2012 14:00 Assunto: Re: Freeradius doesn't record acct-stop-time. On Tue, Feb 7, 2012 at 10:48 PM, Rodrigo Yoshioka <ro_yoshioka2002@yahoo.com.br> wrote:
Hi...
My freeradius are recording in mysql all sessions about start connection, but it didn´t finish it. when a device is logged out it remain connected at mysql, doing my proprietary CRM mistake to return connection data.
Checking detailed log, its registering start connection and stop connection, the problem is just in mysql... It is probably a configuration that I should enable, but I don´t know wich. Can anyone help me.?
Did it suddenly stopped working, or did it never worked at all? Enabling sql in accounting section should handle accounting packets. If you're having problems, running it in debug mode (or enabling sqltrace) might help you find out what queries are being executed, and why they fail (if that's indeed the cause). -- Fajar
AcctTerminateCause should not be empty because there is always a reason for closing session Also, if you're using FR 2.x, default schema should have ... AND AcctStopTime IS NULL ... not ... AND AcctStopTime=0 .... On 2/17/2012 5:55 PM, Rodrigo Yoshioka wrote:
Hi Fajar, I Couldn't solve the problem yet... but I ran the Radius in debug mode, and I tried to disconnect my connection to see what are happening, as I couldn't find, I'll post it here.
Thanks for the help.
rad_recv: Accounting-Request packet from host XXX.XX.X.XXX:37121, id=232, length=268 Service-Type = Framed-User Framed-Protocol = PPP NAS-Port = 115296 NAS-Port-Type = Ethernet User-Name = "email@domain.com.br" Calling-Station-Id = "00:15:6D:E6:94:DB" Called-Station-Id = "pppoe-wip2" NAS-Port-Id = "WIP2" MS-CHAP-Domain = "domain.com.br" Acct-Session-Id = "81514b64" Framed-IP-Address = xxx.xx.X.XX Acct-Authentic = RADIUS Event-Timestamp = "Feb 17 2012 13:44:23 BRST" Acct-Session-Time = 79376 Acct-Input-Octets = 158226957 Acct-Input-Gigawords = 0 Acct-Input-Packets = 1112930 Acct-Output-Octets = 854637707 Acct-Output-Gigawords = 0 Acct-Output-Packets = 1115931 Acct-Status-Type = Stop Acct-Terminate-Cause = NAS-Request NAS-Identifier = "PPPoE-AND WIP2" Acct-Delay-Time = 0 Mikrotik-Realm = "domain.com.br" NAS-IP-Address = xxx.xx.x.xx Processing the preacct section of radiusd.conf modcall: entering group preacct for request 43 modcall[preacct]: module "preprocess" returns noop for request 43 rlm_acct_unique: Hashing 'NAS-Port = 115296,Client-IP-Address = xxx.xx.x.xx,NAS-IP-Address = xxx.xx.x.xxx,Acct-Session-Id = "81514b64",User-Name = "email@domain.com.br"' rlm_acct_unique: Acct-Unique-Session-ID = "4bc00ddcf558a324". modcall[preacct]: module "acct_unique" returns ok for request 43 rlm_realm: Looking up realm "domain.com.br" for User-Name = "email@domain.com.br" rlm_realm: No such realm "domain.com.br" modcall[preacct]: module "suffix" returns noop for request 43 modcall[preacct]: module "files" returns noop for request 43 modcall: leaving group preacct (returns ok) for request 43 Processing the accounting section of radiusd.conf modcall: entering group accounting for request 43 radius_xlat: '/var/log/radacct/xxx.xx.x.xx/detail-20120217' rlm_detail: /var/log/radacct/%{Client-IP-Address}/detail-%Y%m%d expands to /var/log/radacct/xxx.xx.x.xx/detail-20120217 modcall[accounting]: module "detail" returns ok for request 43 modcall[accounting]: module "unix" returns fail for request 43 modcall: leaving group accounting (returns fail) for request 43 Finished request 43 Going to the next request
And the sqltrace, the only information with acct-stop-time is this:
UPDATE radacct SET AcctStopTime='2012-02-10 17:43:19', AcctSessionTime=unix_timestamp('2012-02-10 17:43:19') - unix_timestamp(AcctStartTime), AcctTerminateCause='', AcctStopDelay = '0' WHERE AcctSessionTime=0 AND AcctStopTime=0 AND NASIPAddress= 'xxx.xx.x.xx' AND AcctStartTime <= '2012-02-10 17:43:19';
both were not collected from the same time.
------------------------------------------------------------------------ *De:* Fajar A. Nugraha <list@fajar.net> *Para:* Rodrigo Yoshioka <ro_yoshioka2002@yahoo.com.br>; FreeRadius users mailing list <freeradius-users@lists.freeradius.org> *Enviadas:* Terça-feira, 7 de Fevereiro de 2012 14:00 *Assunto:* Re: Freeradius doesn't record acct-stop-time.
On Tue, Feb 7, 2012 at 10:48 PM, Rodrigo Yoshioka <ro_yoshioka2002@yahoo.com.br <mailto:ro_yoshioka2002@yahoo.com.br>> wrote:
Hi...
My freeradius are recording in mysql all sessions about start connection, but it didn´t finish it. when a device is logged out it remain connected at mysql, doing my proprietary CRM mistake to return connection data.
Checking detailed log, its registering start connection and stop connection, the problem is just in mysql... It is probably a configuration that I should enable, but I don´t know wich. Can anyone help me.?
Did it suddenly stopped working, or did it never worked at all?
Enabling sql in accounting section should handle accounting packets. If you're having problems, running it in debug mode (or enabling sqltrace) might help you find out what queries are being executed, and why they fail (if that's indeed the cause).
-- Fajar
- List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
On Fri, Feb 17, 2012 at 11:31 PM, Rodrigo Yoshioka <ro_yoshioka2002@yahoo.com.br> wrote:
Hi Fajar, I Couldn't solve the problem yet... but I ran the Radius in debug mode, and I tried to disconnect my connection to see what are happening, as I couldn't find, I'll post it here.
Thanks for the help.
rad_recv: Accounting-Request packet from host XXX.XX.X.XXX:37121, id=232, length=268
Acct-Status-Type = Stop
Processing the preacct section of radiusd.conf modcall: entering group preacct for request 43 modcall[preacct]: module "preprocess" returns noop for request 43 rlm_acct_unique: Hashing 'NAS-Port = 115296,Client-IP-Address = xxx.xx.x.xx,NAS-IP-Address = xxx.xx.x.xxx,Acct-Session-Id = "81514b64",User-Name = "email@domain.com.br"' rlm_acct_unique: Acct-Unique-Session-ID = "4bc00ddcf558a324". modcall[preacct]: module "acct_unique" returns ok for request 43 rlm_realm: Looking up realm "domain.com.br" for User-Name = "email@domain.com.br" rlm_realm: No such realm "domain.com.br" modcall[preacct]: module "suffix" returns noop for request 43 modcall[preacct]: module "files" returns noop for request 43 modcall: leaving group preacct (returns ok) for request 43 Processing the accounting section of radiusd.conf modcall: entering group accounting for request 43 radius_xlat: '/var/log/radacct/xxx.xx.x.xx/detail-20120217' rlm_detail: /var/log/radacct/%{Client-IP-Address}/detail-%Y%m%d expands to /var/log/radacct/xxx.xx.x.xx/detail-20120217 modcall[accounting]: module "detail" returns ok for request 43 modcall[accounting]: module "unix" returns fail for request 43 modcall: leaving group accounting (returns fail) for request 43 Finished request 43 Going to the next request
Is that all that's in the debug log? If yes, it's either: - you didn't configure acct section to use sql, because there's nothing mentioning sql from that log. It only says "detail" (which you might or might not need, depending on your setup) and "unix" (which, 99% of the time you won't need). OR - there's some magic (e.g. unlang, multiple virtual servers, etc) in your FR config which skips sql on certain cases, OR - it's a buffered-sql setup, where there should be another virtual server that reads the detail log. Unlikely, since your detail file is dynamic-named I'm guessing it's the first. In any case, it should be easy to check by simply examining acct section in sites-evailable/default (or whatever virtual server you use). As usual, if you're STILL having problems, ask an expert to help. -- Fajar
participants (3)
-
Fajar A. Nugraha -
Marinko Tarlac -
Rodrigo Yoshioka