Handling proxied accounting updates that have been delayed

[Alan DeKok]

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.