accounting to db - duplicate entrys & missing stop time?
Hi, First of all, I'm not very familiar with freeradius, so bear with me. If more specific information is needed, please ask. We have set up freeradius to do accounting to a postgresql database, and I was expecting to see one record pr. session, and mostly we do. But there are also a lot of records that: 1) Do not have a stop time 2) Doesn't even have an Acct-Session-Time 3) Are duplicates I have attached a textfile containing a couple of examples. I am guessing that in case nr. 1 an explicit "Stop" message has not been received, but when it comes to the two others, I have no clue. Is there anything that can be done to avoid the duplicates? Can I get freeradius to log every "Alive" message to the database, so that I at least know when the last "Alive" was received? As I am trying to write an application to more easily extract useful information from the data in the database, I need to know when the session started and when it ended. Having duplicates and missing stop times makes this a bit difficult. If someone could take the time to explain why the stuff I mention here occur, or have tips on other ways to extract the time the session ends, I'd really appreciate it. Regards, Roger Kristiansen manage=> SELECT radacctid, acctuniqueid, username, nasipaddress, nasportid, nasporttype, acctstarttime, acctstoptime, acctsessiontime, acctterminatecause FROM radacct WHERE username LIKE 'xxx000%'; radacctid | acctuniqueid | username | nasipaddress | nasportid | nasporttype | acctstarttime | acctstoptime | acctsessiontime | acctterminatecause -----------+------------------+-----------------------+----------------+-----------+-------------+-------------------------------+-------------------------------+-----------------+-------------------- 49 | f5c3662a11cb9c96 | xxx000@xxx.xxx.xxx | xxx.xxx.xxx.xx | 50027 | Ethernet | 2005-07-13 16:37:56.991037+02 | | | 86 | ba7c66fe30d2e933 | xxx000@xxx.xxx.xxx | xxx.xxx.xxx.xx | 50027 | Ethernet | 2005-07-13 16:52:57.142572+02 | | 27011 | 432 | 328b5aa3cb9c9783 | xxx000@xxx.xxx.xxx | xxx.xxx.xxx.xx | 50027 | Ethernet | 2005-07-14 00:38:08.639255+02 | 2005-07-14 00:58:12.651435+02 | 47121 | Port-Error 608 | f4cde8a7ab4087f4 | xxx000@xxx.xxx.xxx | xxx.xxx.xxx.xx | 50027 | Ethernet | 2005-07-14 09:16:23.006713+02 | | 1 | 627 | f6166e0e52ee5625 | xxx000@xxx.xxx.xxx | xxx.xxx.xxx.xx | 50027 | Ethernet | 2005-07-14 09:31:23.935167+02 | | | manage=> SELECT radacctid, acctuniqueid, username, nasipaddress, nasportid, nasporttype, acctstarttime, acctstoptime, acctsessiontime, acctterminatecause FROM radacct WHERE username LIKE 'yyy022%'; radacctid | acctuniqueid | username | nasipaddress | nasportid | nasporttype | acctstarttime | acctstoptime | acctsessiontime | acctterminatecause -----------+------------------+-------------------------+-----------------+-----------+-------------+-------------------------------+-------------------------------+-----------------+-------------------- 248 | 4b137cbd9d0edc37 | yyy022@yyy.yyy.yyy | yyy.yyy.yyy.yy | 50002 | Ethernet | 2005-07-13 20:35:45.720945+02 | 2005-07-13 20:47:16.888227+02 | 691 | Port-Error 247 | 4b137cbd9d0edc37 | yyy022@yyy.yyy.yyy | yyy.yyy.yyy.yy | 50002 | Ethernet | 2005-07-13 20:35:45.7404+02 | 2005-07-13 20:47:16.888227+02 | 691 | Port-Error
Roger Kristiansen <roger.kristiansen@cc.uit.no> wrote:
We have set up freeradius to do accounting to a postgresql database, and I was expecting to see one record pr. session, and mostly we do. But there are also a lot of records that: ...
Are screwed up. Can you say "NAS implementations are often bad"?
I am guessing that in case nr. 1 an explicit "Stop" message has not been received, but when it comes to the two others, I have no clue.
NAS implementations are bad. FreeRADIUS just logs what it's sent. You can post-process the data to clean it up, but I'm strongly opposed to always processing it before doing the logging. There's just too much of a chance to lose information.
As I am trying to write an application to more easily extract useful information from the data in the database, I need to know when the session started and when it ended. Having duplicates and missing stop times makes this a bit difficult.
Welcome to RADIUS accounting. I'd suggesting looking at "radiusreport", which deals with some of these issues. It may give you ideas as to how to deal with the problems in your application.
Can I get freeradius to log every "Alive" message to the database, so that I at least know when the last "Alive" was received?
See "accounting_update_query", which is run for Alive (i.e. Interim-Update) packets.
If someone could take the time to explain why the stuff I mention here occur, or have tips on other ways to extract the time the session ends, I'd really appreciate it.
If you don't get a stop record, the session ends: a) some time after the last Start or Alive packet was received b) some time before the next Start packet is received for that port. That's pretty much it. Alan DeKok.
Alan DeKok wrote:
Can I get freeradius to log every "Alive" message to the database, so that I at least know when the last "Alive" was received?
See "accounting_update_query", which is run for Alive (i.e. Interim-Update) packets.
Ok, thanks for clearing up a few things. We seem to have gotten things working almost like we wanted to now. But I have one new question regarding the Alive-messages and duplicate entries. I suspect this might have more to do with postgresql than freeradius, but anyway: For some (quite a few, actually) session, we get two almost identical entries. Could this be because freeradius does something like this: 1) Receives a Start packet and inserts a new entry/session in the db 2) Receives Alive packet _immediately_ after the Start packet, and queries the database to see if the unique-session-id already exists. 3) The query doesn't return anything, since postgresql hasn't had time to complete the INSERT-query for the Start packet, and accounting_update_query_alt is thus run. If this is the case, is there any way to fix this behaviour in either freeradius or postgresql? I guess limiting freeradius to one connection would fix it, but.. :) Regards, Roger Kristiansen
Roger Kristiansen <roger.kristiansen@cc.uit.no> wrote:
For some (quite a few, actually) session, we get two almost identical entries.
Could this be because freeradius does something like this:
It logs the packets that the NAS sends. If the NAS sends a number of packets simultaneously, FreeRADIUS will log them all.
If this is the case, is there any way to fix this behaviour in either freeradius or postgresql? I guess limiting freeradius to one connection would fix it, but.. :)
That's pretty much the cause. The solution isn't at all simple. Alan DeKok.
participants (2)
-
Alan DeKok -
Roger Kristiansen