Patric wrote:
When the proxied updates are eventually processed, they are written into my account logs mysql table. The acct_start_time is written as the current date and time, and the acct_delay_time holds the difference between the actual time of the accounting update and now.
Hmm... the session start time is when the packet was sent. *Not* the time it was received (current date && time). It looks like the SQL queries should be updated to reflect this.
As closely as I can tell, this is what I have had happen:
At 08h00 Server A receives a start record. This is put in the detail file to go to Server B. This is also written to the local accounting table with:
acct_start_time = 2009-12-04 08:00:00
The proxy is delayed for 2 hours due to a network issue between Server A and Server B.
OK...
At 09h00 Server B receives the next update stating that user 1 has used 7 input octets. This is put in the detail file to go to Server A. This is also written to the local accounting table with:
acct_start_time = 2009-12-04 09:00:00 acct_input_octets = 7
If it gets an "update", it should set the "start time" as: now() - Acct-Session-Time - Acct-Delay-Time.
This is because the record did not exist so the accounting_update_query_alt was called which inserts instead of updating.
That should be fine.
At 10h00 Server A and Server B can talk to each other, so Server A sends its proxied start record to Server B.
The db record on Server B now reflects:
acct_start_time = 2009-12-04 10:00:00 acct_input_octets = 7 acct_delay_time = 3600 (delayed 2 hours)
Then the start time should be 10am - 2h, or 8am.
Server B also sends its proxied update to server A, and now server A reflects the following:
acct_start_time = 2009-12-04 08:00:00 acct_input_octets = 7
Which should be OK.
So what happened is that server A got the start record and created a new db entry at 08h00. Server B then got an interim update and since the record did not yet exist (proxied start record was delayed), it created its own record at 09h00.
That second step is wrong.
Proxying then started again, and server B received the start record and updated the start time to the current time, 10h00.
That is wrong, too.
Now server A says that the session started at 08h00 and server B says the sessions tarted at 10h00
This is because the entry already existed on server B, so the alternate start query was used, which is currently:
It looks like the queries should be updated to reflect the delay time.
What do you guys do with situations such as these? Do you take into account the acct_delay_time when reporting?
It should be taken into account when writing the "start time" to the DB.
I have been toying with the idea of updating the accounting_start_query_alt not to update the acct_start_time, so basically if the record already exists then leave that as the start time? But as I type it now I realise this will break the delay time calculation so there will be no way to calculate the real start time...
The RADIUS protocol doesn't send a "start time". This is arguably wrong...
Any advise or experiences would be much appreciated!
Fix the SQL queries so that the right information goes into the DB. Note that the calculated times may be off by a second or two, due to limited time resolution. It may be worth updating the server to create a "Acct-Start-Time" attribute. That would simplify a lot of this configuration. Alan DeKok.