Re: [Help-gnu-radius] Acct. warning: acct_stop_query updated X records

[Dale]

--- Sergey Poznyakoff <address@hidden> wrote:
> Hi Dale,
> 
> > A couple times a minute I get either 
> > acct_stop_query updated 0 records OR
> > acct_stop_query updated 2 records
> 
> When the NAS terminates a user's session it sends to the radius
> server
> an accounting request with attribute Acct-Status-Type = Stop (a
> so called 'stop request'). Upon receiving this request, the server
> tries to update the information in the accounting table by executing
> acct_stop_query defined in your raddb/sqlserver. Usually this is
> some sort of SQL 'UPDATE' query. Ideally, this query should alter
> exactly one record. If it alters more recors or doesn't alter any 
> of them, radiusd issues the above diagnostics.
> 
> If the query updated 0 records, this means that the corresponding
> 'start' record was not found in the database. Either it did not
> get there for some reason (the server did not receive the start
> request etc.) or it has already been closed (converted to 'stop'
> record). The latter case is the most common and it means that
> your NAS has sent a *duplicate* 'stop' request to the server.
> If this is the case, this means one of the following:
> 
> I.1)
> Problem: The NAS did not receive accounting reply packet from the
> server.
> Solution: Check your network, firewalls, etc.
> 

If this were the case, it would happen for everyone, right?  It only
happens to a couple percent of the requests so I don't think this is
it.

> I.2)
> Problem: The 'reply expect time' configured on NAS is insufficient
> (For
> example, it waits for 2 seconds before recending the request, whereas
> it
> takes 5 for the server to process it).
> Solution: Synchronise NAS and RADIUS server configuration. On 
> server, the maximum request processing time is set by 'time-to-live'
> statement in 'acct' section. The default value is 60 seconds, which
> is more than enough in any real configuration.
> 

The NAS is set to wait 5 seconds for a reply, with 6 retries.  It also
says that the average response time is 500ms, but a max of 25000ms!  I
think that may be where part of the problem lies.

> Otherwise, if the query updated >1 records, this means that the NAS
> has sent one or more *duplicate* stop records. See points I.1 and I.2
> above. Apart from them, there is also another side in this problem:
> ideally, the server should be able to recognize and drop duplicate
> requests. If it doesn't, this means one of the following problems
> (or both):
> 

I turned on detail logging for a while, and to me the requests look the
same.  Same acct-session-id, same nas-port-id, same nas-ip-address,
etc.

> II.1)
> Problem: Misconfiguration of the server and/or NAS.
> Solution: See section 'Fine-Tuning the Request Queue' in the
> GNU Radius manual
>
(http://www.gnu.org/software/radius/manual/html_node/radius_75.html#SEC152

I've done this - although request-cleanup-delay was set at 2 (to try to
solve a past problem, IIRC).  Changing this to 30-60 seems to have done
nothing.

> 
> II.2)
> Problem: The NAS alters request authenticator and/or request ID
> before
> resending the request.
> Solution: See section 'Extended Comparison' in the GNU Radius manual
>
(http://www.gnu.org/software/radius/manual/html_node/radius_72.html#SEC147)
> 
> All seems to indicate case II.2
> 

Is this fairly common?  I find it odd that several different brands of
NAS's are all having the same "problems" with this.  Since the packets
don't look different in the detail log, how do I go about finding what
is being changed in them?  tcpdump or similar?

Thanks again Sergey,

Dale


        
                
__________________________________
Do you Yahoo!?
Vote for the stars of Yahoo!'s next ad campaign!
http://advision.webevents.yahoo.com/yahoo/votelifeengine/