Accounting responce question.
lamersons
m at baltia.net
Thu May 28 09:53:20 CEST 2009
Hello there, i have posted here few times and got very helpfull answers, so i
desided to try my luck once more.
Im using FreeRADIUS Version 2.0.4(slackware+postgre) on powerfull x86 server
with alot of RAM, connected with gigabit to NAS. Load is about
5-15record/sec
Once in a while we get double accounting records. I started to take traces
at NAS side and saw that sometimes AAA doesnt responce to accounting record,
NAS thinks that AAA didnt get it and sends it one more time. But AAA gets
the first one even if it doesnt responce to request, therefore we get double
record.(debug info is below)
I have made debug trace at AAA side. Is it somehow possible to see from that
trace that AAA did respond and that is NASes(or network) problem that it
did not recieve responce ?(debug info is below)
p.s. -------------------------------------------------------------------
I sent information to NAS vendor:
Dear,
Yesterday at 02:27:38 PDSN sent the "Accounting request start"
message and then PDSN sent the same Accounting request start massage at
02:27:43 (see in traces of PI interface).
Thanks
Best regards,
They answered me:
• The AAA can’t start the new accounting session, until it stops the first
one, so the AAA doesn’t reply to the Accounting Request Start.
• The PDSN wait for TIMEOUT which is 5 seconds, and resend the Accounting
message again.
• When the PDSN resend the Accounting message, the AAA replies to it.
-----------------------------------------------------------------------
########################### First start record : request 11309
Acct-Status-Type = Start
User-Name = "triatel at triatel.lv"
Calling-Station-Id = "247033715823092"
Framed-IP-Address = 192.168.172.128
NAS-IP-Address = 192.168.145.1
Event-Timestamp = "Jul 18 2008 02:27:39 EEST"
Acct-Session-Id = "0000000\000"
NAS-Port-Type = Virtual
NAS-Port = 1813
Acct-Delay-Time = 0
Service-Type = Framed-User
Acct-Authentic = RADIUS
3GPP2-ESN =
"\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000"
3GPP2-Attr-116 = 0x0000000000000000000000000000
3GPP2-Correlation-Id = "17934924"
3GPP2-Service-Reference-Id = 0x0104000102040001
3GPP2-Home-Agent-IP-Address = 0.0.0.0
3GPP2-PCF-IP-Address = 129.11.17.230
3GPP2-BSID = "2A2100021102"
3GPP2-User-Id = 0
3GPP2-Forward-FCH-Mux-Option = 0
3GPP2-Reverse-FCH-Mux-Option = 0
3GPP2-Service-Option = 59
3GPP2-Forward-Traffic-Type = 0
3GPP2-Reverse-Traffic-Type = 0
3GPP2-FCH-Frame-Size = 0
3GPP2-Forward-FCH-RC = 0
3GPP2-Reverse-FCH-RC = 0
3GPP2-IP-Technology = 1
3GPP2-Compulsory-Tunnel-Indicator = 0
3GPP2-DCCH-Frame-Size = 0
3GPP2-Attr-78 = 0x00000000
3GPP2-Forward-PDCH-RC = 0
3GPP2-Forward-DCCH-Mux-Option = 0
3GPP2-Reverse-DCCH-Mux-Option = 0
3GPP2-Forward-DCCH-RC = 0
3GPP2-Reverse-DHHC-RC = 0
3GPP2-Attr-114 = 0x00000000
3GPP2-IP-QoS = 10
3GPP2-Airlink-Priority = 0
+- entering group preacct
rlm_realm: Looking up realm "triatel.lv" for User-Name =
"triatel at triatel.lv"
rlm_realm: No such realm "triatel.lv"
++[suffix] returns noop
+- entering group accounting
rlm_acct_unique: Hashing '3GPP2-Correlation-Id = "17934924",Acct-Session-Id
= "0000000\000",Calling-Station-Id = "247033715823092"'
rlm_acct_unique: Acct-Unique-Session-ID = "33187f91caa26b34".
++[acct_unique] returns ok
expand: %{User-Name} -> triatel at triatel.lv
rlm_sql (sql): sql_set_user escaped user --> 'triatel at triatel.lv'
expand: INSERT into radacct (AcctSessionId, AcctUniqueId,
CallingStationId, AcctStartTime, AcctStopTime, CDMAActiveTime,
AcctInputOctets, AcctOutputOctets, FramedIPAddress, UserName,
ReleaseIndicator, CDMABadPPPFrameCount, CDMACorrelationId, AcctSessionTime,
NASIPAddress) values('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}',
'%{Calling-Station-Id}', '%{Event-Timestamp}', NULL,'0', '0', '0',
'%{Framed-IP-Address}', trim('%{SQL-User-Name}'), '0', '0',
'%{3GPP2-Correlation-Id}', '0', '%{NAS-IP-Address}') -> INSERT into radacct
(AcctSessionId, AcctUniqueId, CallingStationId, AcctStartTime, AcctStopTime,
CDMAActiveTime, AcctInputOctets, AcctOutputOctets, FramedIPAddress,
UserName, ReleaseIndicator, CDMABadPPPFrameCount, CDMACorrelationId,
AcctSessionTime, NASIPAddress) values('0000000', '33187f91caa26b34',
'247033715823092', 'Jul 18 2008 02:27:39 EEST', NULL,'0', '0', '0',
'192.168.172.128', trim('triatel at triatel.lv'), '0', '0', '17934924', '0',
'192.168.145.1')
rlm_sql (sql): Reserving sql socket id: 18
rlm_sql_postgresql: Status: PGRES_COMMAND_OK
rlm_sql_postgresql: query affected rows = 1
rlm_sql (sql): Released sql socket id: 18
++[sql] returns ok
Finished request 11309.
Cleaning up request 11309 ID 18 with timestamp +769
Going to the next request
##################### second Start record : request 11380
Acct-Status-Type = Start
User-Name = "triatel at triatel.lv"
Calling-Station-Id = "247033715823092"
Framed-IP-Address = 192.168.172.128
NAS-IP-Address = 192.168.145.1
Event-Timestamp = "Jul 18 2008 02:27:39 EEST"
Acct-Session-Id = "0000000\000"
NAS-Port-Type = Virtual
NAS-Port = 1813
Acct-Delay-Time = 5
Service-Type = Framed-User
Acct-Authentic = RADIUS
3GPP2-ESN =
"\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000"
3GPP2-Attr-116 = 0x0000000000000000000000000000
3GPP2-Correlation-Id = "17934924"
3GPP2-Service-Reference-Id = 0x0104000102040001
3GPP2-Home-Agent-IP-Address = 0.0.0.0
3GPP2-PCF-IP-Address = 129.11.17.230
3GPP2-BSID = "2A2100021102"
3GPP2-User-Id = 0
3GPP2-Forward-FCH-Mux-Option = 0
3GPP2-Reverse-FCH-Mux-Option = 0
3GPP2-Service-Option = 59
3GPP2-Forward-Traffic-Type = 0
3GPP2-Reverse-Traffic-Type = 0
3GPP2-FCH-Frame-Size = 0
3GPP2-Forward-FCH-RC = 0
3GPP2-Reverse-FCH-RC = 0
3GPP2-IP-Technology = 1
3GPP2-Compulsory-Tunnel-Indicator = 0
3GPP2-DCCH-Frame-Size = 0
3GPP2-Attr-78 = 0x00000000
3GPP2-Forward-PDCH-RC = 0
3GPP2-Forward-DCCH-Mux-Option = 0
3GPP2-Reverse-DCCH-Mux-Option = 0
3GPP2-Forward-DCCH-RC = 0
3GPP2-Reverse-DHHC-RC = 0
3GPP2-Attr-114 = 0x00000000
3GPP2-IP-QoS = 10
3GPP2-Airlink-Priority = 0
+- entering group preacct
rlm_realm: Looking up realm "triatel.lv" for User-Name =
"triatel at triatel.lv"
rlm_realm: No such realm "triatel.lv"
++[suffix] returns noop
+- entering group accounting
rlm_acct_unique: Hashing '3GPP2-Correlation-Id = "17934924",Acct-Session-Id
= "0000000\000",Calling-Station-Id = "247033715823092"'
rlm_acct_unique: Acct-Unique-Session-ID = "33187f91caa26b34".
++[acct_unique] returns ok
expand: %{User-Name} -> triatel at triatel.lv
rlm_sql (sql): sql_set_user escaped user --> 'triatel at triatel.lv'
expand: INSERT into radacct (AcctSessionId, AcctUniqueId,
CallingStationId, AcctStartTime, AcctStopTime, CDMAActiveTime,
AcctInputOctets, AcctOutputOctets, FramedIPAddress, UserName,
ReleaseIndicator, CDMABadPPPFrameCount, CDMACorrelationId, AcctSessionTime,
NASIPAddress) values('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}',
'%{Calling-Station-Id}', '%{Event-Timestamp}', NULL,'0', '0', '0',
'%{Framed-IP-Address}', trim('%{SQL-User-Name}'), '0', '0',
'%{3GPP2-Correlation-Id}', '0', '%{NAS-IP-Address}') -> INSERT into radacct
(AcctSessionId, AcctUniqueId, CallingStationId, AcctStartTime, AcctStopTime,
CDMAActiveTime, AcctInputOctets, AcctOutputOctets, FramedIPAddress,
UserName, ReleaseIndicator, CDMABadPPPFrameCount, CDMACorrelationId,
AcctSessionTime, NASIPAddress) values('0000000', '33187f91caa26b34',
'247033715823092', 'Jul 18 2008 02:27:39 EEST', NULL,'0', '0', '0',
'192.168.172.128', trim('triatel at triatel.lv'), '0', '0', '17934924', '0',
'192.168.145.1')
rlm_sql (sql): Reserving sql socket id: 43
rlm_sql_postgresql: Status: PGRES_FATAL_ERROR
rlm_sql_postgresql: Error duplicate key value violates unique constraint
"radacct_acctuniqueid"
rlm_sql_postgresql: Postgresql Fatal Error: [23505: UNIQUE VIOLATION]
Occurred!!
rlm_sql (sql): Couldn't insert SQL accounting START record - ERROR:
duplicate key value violates unique constraint "radacct_acctuniqueid"
expand: ->
rlm_sql (sql): Released sql socket id: 43
++[sql] returns ok
Finished request 11380.
############################## Interim record ###################
Ready to process requests.
Acct-Status-Type = Interim-Update
User-Name = "triatel at triatel.lv"
Calling-Station-Id = "247033715823092"
Framed-IP-Address = 192.168.172.128
NAS-IP-Address = 192.168.145.1
Event-Timestamp = "Jul 18 2008 02:42:39 EEST"
Acct-Session-Id = "0000000\000"
NAS-Port-Type = Virtual
NAS-Port = 1813
Acct-Delay-Time = 0
Acct-Session-Time = 900
Acct-Output-Octets = 0
Acct-Input-Octets = 0
Acct-Input-Packets = 0
Acct-Output-Packets = 0
Acct-Multi-Session-Id = "17934924"
Service-Type = Framed-User
Acct-Authentic = RADIUS
3GPP2-ESN =
"\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000"
3GPP2-Attr-116 = 0x0000000000000000000000000000
3GPP2-Correlation-Id = "17934924"
3GPP2-Session-Continue = 1
3GPP2-Service-Reference-Id = 0x0104000102040001
3GPP2-Home-Agent-IP-Address = 0.0.0.0
3GPP2-PCF-IP-Address = 129.11.17.230
3GPP2-BSID = "2A2100021102"
3GPP2-User-Id = 0
3GPP2-Forward-FCH-Mux-Option = 0
3GPP2-Reverse-FCH-Mux-Option = 0
3GPP2-Service-Option = 59
3GPP2-Forward-Traffic-Type = 0
3GPP2-Reverse-Traffic-Type = 0
3GPP2-FCH-Frame-Size = 0
3GPP2-Forward-FCH-RC = 0
3GPP2-Reverse-FCH-RC = 0
3GPP2-IP-Technology = 1
3GPP2-Compulsory-Tunnel-Indicator = 0
3GPP2-DCCH-Frame-Size = 0
3GPP2-Attr-78 = 0x00000000
3GPP2-Forward-PDCH-RC = 0
3GPP2-Forward-DCCH-Mux-Option = 0
3GPP2-Reverse-DCCH-Mux-Option = 0
3GPP2-Forward-DCCH-RC = 0
3GPP2-Reverse-DHHC-RC = 0
3GPP2-Attr-114 = 0x00000000
3GPP2-Bad-PPP-Frame-Count = 0
3GPP2-Active-Time = 33
3GPP2-Number-Active-Transitions = 0
3GPP2-Received-HDLC-Octets = 0
3GPP2-Inbound-Mobile-IP-Sig-Octets = 0
3GPP2-Outbound-Mobile-IP-Sig-Octets = 0
3GPP2-Last-User-Activity-Time = 1216337292
3GPP2-IP-QoS = 10
3GPP2-Airlink-Priority = 0
+- entering group preacct
rlm_realm: Looking up realm "triatel.lv" for User-Name =
"triatel at triatel.lv"
rlm_realm: No such realm "triatel.lv"
++[suffix] returns noop
+- entering group accounting
rlm_acct_unique: Hashing '3GPP2-Correlation-Id = "17934924",Acct-Session-Id
= "0000000\000",Calling-Station-Id = "247033715823092"'
rlm_acct_unique: Acct-Unique-Session-ID = "33187f91caa26b34".
++[acct_unique] returns ok
expand: %{User-Name} -> triatel at triatel.lv
rlm_sql (sql): sql_set_user escaped user --> 'triatel at triatel.lv'
expand: ->
rlm_sql (sql): Reserving sql socket id: 2
rlm_sql (sql): Released sql socket id: 2
++[sql] returns ok
Finished request 21837.
##########################################STOP record ##########
Acct-Status-Type = Stop
User-Name = "triatel at triatel.lv"
Calling-Station-Id = "247033715823092"
Framed-IP-Address = 192.168.172.128
NAS-IP-Address = 192.168.145.1
Event-Timestamp = "Jul 18 2008 02:43:01 EEST"
Acct-Session-Id = "0000000\000"
NAS-Port-Type = Virtual
NAS-Port = 1813
Acct-Delay-Time = 0
Acct-Session-Time = 922
Acct-Output-Octets = 0
Acct-Input-Octets = 0
Acct-Input-Packets = 0
Acct-Output-Packets = 0
Acct-Terminate-Cause = Idle-Timeout
Acct-Multi-Session-Id = "17934924"
Service-Type = Framed-User
Acct-Authentic = RADIUS
3GPP2-ESN =
"\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000"
3GPP2-Attr-116 = 0x0000000000000000000000000000
3GPP2-Correlation-Id = "17934924"
3GPP2-Session-Continue = 0
3GPP2-Service-Reference-Id = 0x0104000102040001
3GPP2-Home-Agent-IP-Address = 0.0.0.0
3GPP2-PCF-IP-Address = 129.11.17.230
3GPP2-BSID = "2A2100021102"
3GPP2-User-Id = 0
3GPP2-Forward-FCH-Mux-Option = 0
3GPP2-Reverse-FCH-Mux-Option = 0
3GPP2-Service-Option = 59
3GPP2-Forward-Traffic-Type = 0
3GPP2-Reverse-Traffic-Type = 0
3GPP2-FCH-Frame-Size = 0
3GPP2-Forward-FCH-RC = 0
3GPP2-Reverse-FCH-RC = 0
3GPP2-IP-Technology = 1
3GPP2-Compulsory-Tunnel-Indicator = 0
3GPP2-Release-Indicator = 7
3GPP2-DCCH-Frame-Size = 0
3GPP2-Attr-78 = 0x00000000
3GPP2-Forward-PDCH-RC = 0
3GPP2-Forward-DCCH-Mux-Option = 0
3GPP2-Reverse-DCCH-Mux-Option = 0
3GPP2-Forward-DCCH-RC = 0
3GPP2-Reverse-DHHC-RC = 0
3GPP2-Attr-114 = 0x00000000
3GPP2-Bad-PPP-Frame-Count = 0
3GPP2-Active-Time = 33
3GPP2-Number-Active-Transitions = 0
3GPP2-Received-HDLC-Octets = 0
3GPP2-Inbound-Mobile-IP-Sig-Octets = 0
3GPP2-Outbound-Mobile-IP-Sig-Octets = 0
3GPP2-Last-User-Activity-Time = 1216337292
3GPP2-IP-QoS = 10
3GPP2-Airlink-Priority = 0
+- entering group preacct
rlm_realm: Looking up realm "triatel.lv" for User-Name =
"triatel at triatel.lv"
rlm_realm: No such realm "triatel.lv"
++[suffix] returns noop
+- entering group accounting
rlm_acct_unique: Hashing '3GPP2-Correlation-Id = "17934924",Acct-Session-Id
= "0000000\000",Calling-Station-Id = "247033715823092"'
rlm_acct_unique: Acct-Unique-Session-ID = "33187f91caa26b34".
++[acct_unique] returns ok
expand: %{User-Name} -> triatel at triatel.lv
rlm_sql (sql): sql_set_user escaped user --> 'triatel at triatel.lv'
expand: UPDATE radacct SET AcctStopTime = '%{Event-Timestamp}',
AcctSessionTime = '%{Acct-Session-Time}', AcctInputOctets =
'%{Acct-Input-Octets}', OutputPacket = '%{Acct-Output-Packets}', InputPacket
= '%{Acct-Input-Packets}', AcctOutputOctets = '%{Acct-Output-Octets}',
ReleaseIndicator = '%{Acct-Terminate-Cause}', CDMABadPPPFrameCount =
'%{3GPP2-Bad-PPP-Frame-Count}', CDMACorrelationId =
'%{3GPP2-Correlation-Id}', CDMAActiveTime = '%{3GPP2-Active-Time}' WHERE
AcctUniqueId = '%{Acct-Unique-Session-Id}' -> UPDATE radacct SET
AcctStopTime = 'Jul 18 2008 02:43:01 EEST', AcctSessionTime = '922',
AcctInputOctets = '0', OutputPacket = '0', InputPacket = '0',
AcctOutputOctets = '0', ReleaseIndicator = 'Idle-Timeout',
CDMABadPPPFrameCount = '0', CDMACorrelationId = '17934924', CDMAActiveTime =
'33' WHERE AcctUniqueId = '33187f91caa26b34'
rlm_sql (sql): Reserving sql socket id: 25
rlm_sql_postgresql: Status: PGRES_COMMAND_OK
rlm_sql_postgresql: query affected rows = 1
rlm_sql (sql): Released sql socket id: 25
++[sql] returns ok
Finished request 22102.
--
View this message in context: http://www.nabble.com/Accounting-responce-question.-tp23756895p23756895.html
Sent from the FreeRadius - User mailing list archive at Nabble.com.
More information about the Freeradius-Users
mailing list