(RADIATOR) Double Accounting Stops - How to ignore one?
Hugh Irvine
hugh at open.com.au
Wed May 18 20:30:36 CDT 2005
Hello Lim -
I agree with Frank Danielson (hello Frank) that this looks very much
like a NAS bug.
My usual recommendation is to use a LASTACCTUPDATE column in the user
record and check it and update it with the Timestamp from the
accounting request so you only ever do one update for any particular
accounting event for a user.
This topic has been discussed on the mailing list:
www.open.com.au/archives/radiator
regards
Hugh
On 19 May 2005, at 00:32, Kheng Teong, Lim wrote:
> Somehow or rather, once in a while, we get two (double) Accounting
> Stops from some NASes.
> It doesn't happen often, but when it does, it will cause problems
> as we're running a prepaid system that deducts time and bandwidth
> from the user's time/bandwidth bank.
> Once this happens, a user's actual prepaid time/bandwidth will be
> double deducted.
>
> Is there a way to get Radiator to ignore one of the Accounting Stops?
> If yes, how do we go about configuring Radiator to only utilize one
> Accounting Stop instead of both when it happens?
>
> Thanks in advance!
>
> [Extract from logfile]
> Tue May 17 15:34:52 2005: DEBUG: Adding Clients from SQL database
> Tue May 17 15:34:52 2005: DEBUG: Query is: 'select
> NASIDENTIFIER,
> SECRET,
> IGNOREACCTSIGNATURE,
> DUPINTERVAL,
> DEFAULTREALM,
> NASTYPE,
> SNMPCOMMUNITY,
> LIVINGSTONOFFS,
> LIVINGSTONHOLE,
> FRAMEDGROUPBASEADDRESS,
> FRAMEDGROUPMAXPORTSPERCLASSC,
> REWRITEUSERNAME,
> NOIGNOREDUPLICATES,
> PREHANDLERHOOK from RADCLIENTLIST':
>
> Tue May 17 15:34:52 2005: DEBUG: Finished reading configuration
> file '/etc/radiator/radius.cfg'
> Tue May 17 15:34:52 2005: DEBUG: Reading dictionary file '/etc/
> radiator/dictionary'
> Tue May 17 15:34:52 2005: DEBUG: Creating authentication port
> 0.0.0.0:1645
> Tue May 17 15:34:52 2005: DEBUG: Creating accounting port 0.0.0.0:1646
> Tue May 17 15:34:52 2005: NOTICE: Server started: Radiator 3.8 on
> AAAtlas
> Tue May 17 15:35:02 2005: DEBUG: Packet dump:
>
> Tue May 17 16:07:29 2005: DEBUG: Packet dump:
> *** Received from 192.168.51.27 port 1025 ....
> Code: Access-Request
> Identifier: 0
> Authentic:
> <142><159><176>O<127><172>M<245>B<221><31>s4<204><250><166>
> Attributes:
> User-Name = "deleted"
> CHAP-Challenge = 9<220>+<16><142>*<242><232><194>
> \<141><15><221><199><12><188>
> CHAP-Password =
> <208><160><247><21><31><175>Nw<182><189><218><9><215><150><26>;=
> Calling-Station-Id = "172.16.1.14"
> Service-Type = Authenticate-Only
> NAS-Identifier = "My Unique Server Name"
> NAS-Port = 0
>
> Tue May 17 16:07:29 2005: DEBUG: Handling request with Handler
> 'Realm=DEFAULT'
> Tue May 17 16:07:29 2005: DEBUG: SQLSESSIONDB Deleting session for
> deleted, 192.168.51.27, 0
> Tue May 17 16:07:29 2005: DEBUG: do query is: 'delete from
> RADONLINE where ACCTSESSIONID = NULL':
>
> Tue May 17 16:07:29 2005: DEBUG: Handling with Radius::AuthSQL
> Tue May 17 16:07:29 2005: DEBUG: Handling with Radius::AuthSQL:
> SUBSCRIBERS
> Tue May 17 16:07:29 2005: DEBUG: Query is: 'select PASS_WORD,
> STATICADDRESS, TIMELEFT, MAXLOGINS, SERVICENAME, BADLOGINS,
> VALIDFROM, VALIDTO, VNC_PPPOE_CBQ_RX, VNC_PPPOE_CBQ_TX,
> VNC_PPPOE_CBQ_RX_FALLBACK, VNC_PPPOE_CBQ_TX_FALLBACK, SPLASH from
> RADUSERS where USERNAME='deleted' and TIMELEFT > 0 and VALIDFROM <
> 1116317249 and VALIDTO > 1116317249 and ACCOUNTSTATUS > 0 and
> TOTALOCTETSLEFT > 0':
>
> Tue May 17 16:07:29 2005: DEBUG: Radius::AuthSQL looks for match
> with deleted
> Tue May 17 16:07:29 2005: DEBUG: Query is: 'select NASIDENTIFIER,
> NASPORT, ACCTSESSIONID, FRAMEDIPADDRESS from RADONLINE where
> username = 'deleted'':
>
> Tue May 17 16:07:29 2005: DEBUG: Radius::AuthSQL ACCEPT:
> Tue May 17 16:07:29 2005: DEBUG: Access accepted for deleted
> Tue May 17 16:07:29 2005: DEBUG: do query is: 'insert into
> RADAUTHLOG (TIME_STAMP, USERNAME, TYPE) values (1116317249,
> 'deleted', 1)':
>
> Tue May 17 16:07:29 2005: DEBUG: Packet dump:
> *** Sending to 192.168.51.27 port 1025 ....
> Code: Access-Accept
> Identifier: 0
> Authentic:
> <142><159><176>O<127><172>M<245>B<221><31>s4<204><250><166>
> Attributes:
> Session-Timeout = 2409993
> VNC-PPPoE-CBQ-RX = 512000
> VNC-PPPoE-CBQ-TX = 256000
> VNC-PPPoE-CBQ-RX-Fallback = 0
> VNC-PPPoE-CBQ-TX-Fallback = 0
> splash = 1
>
> Tue May 17 16:07:30 2005: DEBUG: Packet dump:
> *** Received from 192.168.51.27 port 1025 ....
> Code: Accounting-Request
> Identifier: 1
> Authentic: <128>"<130>Q+<188><24>Q<169>xB<154><143><146>8<228>
> Attributes:
> Acct-Session-Id = "4528485e550"
> User-Name = "deleted"
> Calling-Station-Id = "172.16.1.14"
> Acct-Status-Type = Start
> Service-Type = Framed-User
> Framed-Protocol = PPP
> Acct-Authentic = RADIUS
> NAS-Port-Type = Async
> NAS-Identifier = "My Unique Server Name"
> NAS-Port = 0
> Acct-Delay-Time = 0
>
> Tue May 17 16:07:30 2005: DEBUG: Handling request with Handler
> 'Realm=DEFAULT'
> Tue May 17 16:07:30 2005: DEBUG: SQLSESSIONDB Adding session for
> deleted, 192.168.51.27, 0
> Tue May 17 16:07:30 2005: DEBUG: do query is: 'delete from
> RADONLINE where ACCTSESSIONID = '4528485e550'':
>
> Tue May 17 16:07:30 2005: DEBUG: do query is: 'insert into
> RADONLINE (USERNAME, NASIDENTIFIER, NASPORT, ACCTSESSIONID,
> TIME_STAMP, FRAMEDIPADDRESS, NASPORTTYPE, SERVICETYPE) values
> ('deleted', '192.168.51.27', 0, '4528485e550', 1116317250,
> '172.16.1.14', 'Async', 'Framed-User')':
>
> Tue May 17 16:07:30 2005: DEBUG: Handling with Radius::AuthSQL
> Tue May 17 16:07:30 2005: DEBUG: Handling accounting with
> Radius::AuthSQL
> Tue May 17 16:07:30 2005: DEBUG: Accounting accepted
> Tue May 17 16:07:30 2005: DEBUG: Packet dump:
> *** Sending to 192.168.51.27 port 1025 ....
> Code: Accounting-Response
> Identifier: 1
> Authentic: <128>"<130>Q+<188><24>Q<169>xB<154><143><146>8<228>
> Attributes:
>
> Tue May 17 16:07:35 2005: DEBUG: Packet dump:
> *** Received from 192.168.51.27 port 1025 ....
> Code: Accounting-Request
> Identifier: 2
> Authentic: <172>j<252><18><242>b:<251><168><181>-<188>a<139>i<25>
> Attributes:
> Acct-Session-Id = "4528485e550"
> User-Name = "deleted"
> Calling-Station-Id = "172.16.1.14"
> Acct-Status-Type = Stop
> Service-Type = Framed-User
> Framed-Protocol = PPP
> Acct-Authentic = RADIUS
> Acct-Session-Time = 5
> Acct-Output-Octets = 30892
> Acct-Input-Octets = 2913
> Acct-Output-Packets = 58
> Acct-Input-Packets = 28
> NAS-Port-Type = Async
> NAS-Identifier = "My Unique Server Name"
> NAS-Port = 0
> Acct-Delay-Time = 0
>
> Tue May 17 16:07:35 2005: DEBUG: Handling request with Handler
> 'Realm=DEFAULT'
> Tue May 17 16:07:35 2005: DEBUG: SQLSESSIONDB Deleting session for
> deleted, 192.168.51.27, 0
> Tue May 17 16:07:35 2005: DEBUG: do query is: 'delete from
> RADONLINE where ACCTSESSIONID = '4528485e550'':
>
> Tue May 17 16:07:35 2005: DEBUG: Handling with Radius::AuthSQL
> Tue May 17 16:07:35 2005: DEBUG: Handling accounting with
> Radius::AuthSQL
> Tue May 17 16:07:35 2005: DEBUG: do query is: 'update RADUSERS set
> TIMELEFT=TIMELEFT-05, OCTETSINLEFT=OCTETSINLEFT-02913,
> OCTETSOUTLEFT=OCTETSOUTLEFT-030892,
> TOTALOCTETSLEFT=TOTALOCTETSLEFT-02913,
> TOTALOCTETSLEFT=TOTALOCTETSLEFT-030892 where USERNAME='deleted'':
>
> Tue May 17 16:07:35 2005: DEBUG: do query is: 'insert into RADUSAGE
> (ACCTDELAYTIME,ACCTINPUTOCTETS,ACCTOUTPUTOCTETS,ACCTSESSIONID,ACCTSESS
> IONTIME,ACCTSTATUSTYPE,FRAMEDIPADDRESS,NASIDENTIFIER,NASPORT,TIME_STAM
> P,USERNAME) values (0,2913,30892,'4528485e550',
> 5,2,'172.16.1.14','My Unique Server Name',0,1116317255-05,'deleted')':
>
> Tue May 17 16:07:35 2005: DEBUG: Accounting accepted
> Tue May 17 16:07:35 2005: DEBUG: Packet dump:
> *** Sending to 192.168.51.27 port 1025 ....
> Code: Accounting-Response
> Identifier: 2
> Authentic: <172>j<252><18><242>b:<251><168><181>-<188>a<139>i<25>
> Attributes:
>
> Tue May 17 16:07:35 2005: DEBUG: Packet dump:
> *** Received from 192.168.51.27 port 1025 ....
> Code: Accounting-Request
> Identifier: 3
> Authentic: <255><162><129><215><190><24><136>
> $<13>0<23><144><145><217><226><244>
> Attributes:
> Acct-Session-Id = "4528485e550"
> User-Name = "deleted"
> Calling-Station-Id = "172.16.1.14"
> Acct-Status-Type = Stop
> Service-Type = Framed-User
> Framed-Protocol = PPP
> Acct-Authentic = RADIUS
> Acct-Session-Time = 5
> Acct-Output-Octets = 30892
> Acct-Input-Octets = 2913
> Acct-Output-Packets = 58
> Acct-Input-Packets = 28
> NAS-Port-Type = Async
> NAS-Identifier = "My Unique Server Name"
> NAS-Port = 0
> Acct-Delay-Time = 0
>
> Tue May 17 16:07:35 2005: DEBUG: Handling request with Handler
> 'Realm=DEFAULT'
> Tue May 17 16:07:35 2005: DEBUG: SQLSESSIONDB Deleting session for
> deleted, 192.168.51.27, 0
> Tue May 17 16:07:35 2005: DEBUG: do query is: 'delete from
> RADONLINE where ACCTSESSIONID = '4528485e550'':
>
> Tue May 17 16:07:35 2005: DEBUG: Handling with Radius::AuthSQL
> Tue May 17 16:07:35 2005: DEBUG: Handling accounting with
> Radius::AuthSQL
> Tue May 17 16:07:35 2005: DEBUG: do query is: 'update RADUSERS set
> TIMELEFT=TIMELEFT-05, OCTETSINLEFT=OCTETSINLEFT-02913,
> OCTETSOUTLEFT=OCTETSOUTLEFT-030892,
> TOTALOCTETSLEFT=TOTALOCTETSLEFT-02913,
> TOTALOCTETSLEFT=TOTALOCTETSLEFT-030892 where USERNAME='deleted'':
>
> Tue May 17 16:07:35 2005: DEBUG: do query is: 'insert into RADUSAGE
> (ACCTDELAYTIME,ACCTINPUTOCTETS,ACCTOUTPUTOCTETS,ACCTSESSIONID,ACCTSESS
> IONTIME,ACCTSTATUSTYPE,FRAMEDIPADDRESS,NASIDENTIFIER,NASPORT,TIME_STAM
> P,USERNAME) values (0,2913,30892,'4528485e550',
> 5,2,'172.16.1.14','My Unique Server Name',0,1116317255-05,'deleted')':
>
> Tue May 17 16:07:35 2005: DEBUG: Accounting accepted
> Tue May 17 16:07:35 2005: DEBUG: Packet dump:
> *** Sending to 192.168.51.27 port 1025 ....
> Code: Accounting-Response
> Identifier: 3
> Authentic: <255><162><129><215><190><24><136>
> $<13>0<23><144><145><217><226><244>
> Attributes:
>
> Thanks
>
> --
> Warm Regards,
> Kheng Teong, Lim
>
> Chief Technology Officer
> Red Tree Ventures Sdn. Bhd.
> -----------------------------------------------------------
> Red Tree Ventures Sdn. Bhd.
> No. 119, (3rd Floor) Jalan SS6/12,
> Kelana Jaya Urban Centre,
> 47301 Petaling Jaya,
> Selangor Darul Ehsan, MALAYSIA.
> Tel: 03-7880 6580 / Fax: 03-7880 6590
> http://www.redtreeunwired.com
> ------------------------------------------------------------
NB:
Have you read the reference manual ("doc/ref.html")?
Have you searched the mailing list archive (www.open.com.au/archives/
radiator)?
Have you had a quick look on Google (www.google.com)?
Have you included a copy of your configuration file (no secrets),
together with a trace 4 debug showing what is happening?
--
Radiator: the most portable, flexible and configurable RADIUS server
anywhere. Available on *NIX, *BSD, Windows, MacOS X.
-
Nets: internetwork inventory and management - graphical, extensible,
flexible with hardware, software, platform and database independence.
-
CATool: Private Certificate Authority for Unix and Unix-like systems.
--
Archive at http://www.open.com.au/archives/radiator/
Announcements on radiator-announce at open.com.au
To unsubscribe, email 'majordomo at open.com.au' with
'unsubscribe radiator' in the body of the message.
More information about the radiator
mailing list