Hi,
I am using SQL authentification and accounting with Radiator-2.16.3 and
MySQL 3.22.32.
I noticed that sometimes, client IP is not saved in accounting tables and in
the same time, its state is not put to 0 after the end of the session.
Here are the interesting debug lines :
Thu Sep 28 09:13:43 2000: DEBUG: do query is: insert into 2000_09_28
(USERNAME, TIME_STAMP, ACCTSTATUSTYPE, ACCTDELAYTIME, ACCTINPUTOCTETS,
ACCTOUTPUTOCTETS, ACCTSESSIONID, ACCTSESSIONTIME, NASPORT, CALLINGID,
CALLEDID)
values
('carrefour', 970125223, 'Stop', 0, 294, 153, '0000015A', 4, 20,
'608715017', '6641')
Thu Sep 28 09:13:43 2000: DEBUG: Handling with Radius::AuthDYNADDRESS
Thu Sep 28 09:13:43 2000: DEBUG: do query is: update RADPOOL set STATE=0,
TIME_STAMP=970125223
where YIADDR=''
You can see here that FRAMEDIPADDRESS is not in the "insert" SQL request and
YIADDR is empty in the "update" SQL request.
That problem doesn't occur sytematically and you see below that sometimes,
everything is OK (I didn't change anything between the 2 cases)
Thu Sep 28 09:15:51 2000: DEBUG: do query is: insert into 2000_09_28
(USERNAME, TIME_STAMP, ACCTSTATUSTYPE, ACCTDELAYTIME, ACCTINPUTOCTETS,
ACCTOUTPUTOCTETS, ACCTSESSIONID, ACCTSESSIONTIME, NASPORT, FRAMEDIPADDRESS,
CALLINGID, CALLEDID)
values
('carrefour', 970125351, 'Stop', 0, 554, 1506, '0000015C', 122, 11,
'10.69.1.42', '670487956', '6641')
Thu Sep 28 09:15:51 2000: DEBUG: Handling with Radius::AuthDYNADDRESS
Thu Sep 28 09:15:51 2000: DEBUG: do query is: update RADPOOL set STATE=0,
TIME_STAMP=970125351
where YIADDR='10.69.1.42'
Any idea about that problem ? Thanks in advance for your help. Gildas.
Foreground
Trace 4
AuthPort 1645
AcctPort 1646
LogDir /var/log/radiator
DbDir /usr/local/etc/radiator
LogFile %L//%Y%m/radiator-%Y%m%d
DictionaryFile %D/dictionary
#PidFile %L/radiator.pid
PidFile /tmp/radiator.pid
# Mise en minuscules des username pour l'accounting
# car l'authentification MySQL est insensible a la caste
RewriteUsername tr/A-Z/a-z/
<Client DEFAULT>
Secret *****
# Adresse de base pour le Framed-Group = 0 : IP = cette IP + NAS-Port
# FramedGroupBaseAddress 10.69.1.30
</Client>
# Plages d'adresses IP pour table RADPOOL
<AddressAllocator SQL>
Identifier SQLAllocator
DBSource dbi:mysql:radius
DBUsername radiator
DBAuth ra1diator
<AddressPool Test>
Subnetmask 255.255.255.0
Range 10.69.1.199 10.69.1.199
</AddressPool>
<AddressPool Public>
Subnetmask 255.255.255.0
Range 10.69.1.200 10.69.1.253
</AddressPool>
<AddressPool Fluxus>
Subnetmask 255.255.255.0
Range 10.69.1.25 10.69.1.39
</AddressPool>
<AddressPool Carrefour>
Subnetmask 255.255.255.0
Range 10.69.1.40 10.69.1.54
</AddressPool>
</AddressAllocator>
# Appel sur le 66 42
#<Handler Called-Station-Id = 6642>
<Handler>
SessionDatabase SDBSQL
# <AuthBy FILE>
# Filename %D/users.6642
# Nocache
AuthByPolicy ContinueWhileAccept
<AuthBy SQL>
DBSource dbi:mysql:radius
DBUsername radiator
DBAuth ra1diator
AuthSelect select PASSWORD, CHECKATTR, REPLYATTR \
from SUBSCRIBERS where USERNAME = '%n'
</AuthBy>
<AuthBy SQL>
DBSource dbi:mysql:radius
DBUsername radiator
DBAuth ra1diator
AuthSelect select NULL, CHECKATTR, REPLYATTR from SUBSCRIBERS where
USERNAME = 'DEFAULT'
AccountingStopsOnly
AccountingTable %Y_%m_%d
AcctColumnDef USERNAME,User-Name
AcctColumnDef TIME_STAMP,Timestamp,integer
AcctColumnDef ACCTSTATUSTYPE,Acct-Status-Type
AcctColumnDef ACCTDELAYTIME,Acct-Delay-Time,integer
AcctColumnDef ACCTINPUTOCTETS,Acct-Input-Octets,integer
AcctColumnDef ACCTOUTPUTOCTETS,Acct-Output-Octets,integer
AcctColumnDef ACCTSESSIONID,Acct-Session-Id
AcctColumnDef ACCTSESSIONTIME,Acct-Session-Time,integer
AcctColumnDef NASPORT,NAS-Port,integer
AcctColumnDef FRAMEDIPADDRESS,Framed-IP-Address
AcctColumnDef CALLINGID, Calling-Station-Id
AcctColumnDef CALLEDID, Called-Station-Id
</AuthBy>
<AuthBy DYNADDRESS>
Allocator SQLAllocator
StripFromReply PoolHint
</AuthBy>
</Handler>
#<Handler>
# AcctLogFileName %L/%Y%m/account-%Y%m%d
# # permet d'avoir plusieurs AuthBy
# AuthByPolicy ContinueWhileReject
# <AuthBy FILE>
# Filename %D/wap
# FramedGroup 0
# </AuthBy>
# <AuthBy FILE>
# Filename %D/kit
# </AuthBy>
#</Handler>
# Base de donnees des sessions ouvertes
<SessionDatabase SQL>
Identifier SDBSQL
DBSource dbi:mysql:radius
DBUsername radiator
DBAuth ra1diator
AddQuery insert into ONLINE (USERNAME, NASIDENTIFIER, NASPORT, \
ACCTSESSIONID, TIME_STAMP, FRAMEDIPADDRESS, CALLINGID, CALLEDID) \
values ('%n', '%N', %{NAS-Port}, '%{Acct-Session-Id}', \
%{Timestamp}, '%{Framed-IP-Address}', %{Calling-Station-Id},
%{Called-Station-Id} )
DeleteQuery delete from ONLINE where USERNAME='%n' and NASPORT=%{NAS-Port}
</SessionDatabase>
Thu Sep 28 09:13:39 2000: DEBUG: Packet dump:
*** Received from 10.69.1.1 port 1645 ....
Code: Access-Request
Identifier: 69
Authentic: <236><0><24>fp<228><142>1<192>F<129><134><19><205>g<162>
Attributes:
NAS-IP-Address = 10.69.1.1
NAS-Port = 20
NAS-Port-Type = Async
User-Name = "Carrefour"
Called-Station-Id = "6641"
Calling-Station-Id = "608715017"
CHAP-Password =
"<9><206><243><239><243><255>V<218>G<183><15><31><229><188><246><8>F"
Service-Type = Framed-User
Framed-Protocol = PPP
Thu Sep 28 09:13:39 2000: DEBUG: Rewrote user name to carrefour
Thu Sep 28 09:13:39 2000: DEBUG: Check if Handler should be used to handle this
request
Thu Sep 28 09:13:39 2000: DEBUG: Handling request with Handler ''
Thu Sep 28 09:13:39 2000: DEBUG: SDBSQL Deleting session for Carrefour, 10.69.1.1, 20
Thu Sep 28 09:13:39 2000: DEBUG: do query is: delete from ONLINE where
USERNAME='carrefour' and NASPORT=20
Thu Sep 28 09:13:39 2000: DEBUG: Handling with Radius::AuthSQL
Thu Sep 28 09:13:39 2000: DEBUG: Handling with Radius::AuthSQL
Thu Sep 28 09:13:39 2000: DEBUG: Query is: select PASSWORD, CHECKATTR, REPLYATTR from
SUBSCRIBERS where USERNAME = 'carrefour'
Thu Sep 28 09:13:39 2000: DEBUG: Radius::AuthSQL looks for match with carrefour
Thu Sep 28 09:13:39 2000: DEBUG: Radius::AuthSQL ACCEPT:
Thu Sep 28 09:13:39 2000: DEBUG: Handling with Radius::AuthSQL
Thu Sep 28 09:13:39 2000: DEBUG: Handling with Radius::AuthSQL
Thu Sep 28 09:13:39 2000: DEBUG: Query is: select NULL, CHECKATTR, REPLYATTR from
SUBSCRIBERS where USERNAME = 'DEFAULT'
Thu Sep 28 09:13:39 2000: DEBUG: Radius::AuthSQL looks for match with carrefour
Thu Sep 28 09:13:39 2000: DEBUG: Radius::AuthSQL ACCEPT:
Thu Sep 28 09:13:39 2000: DEBUG: Handling with Radius::AuthDYNADDRESS
Thu Sep 28 09:13:39 2000: DEBUG: Query is: select YIADDR, SUBNETMASK, DNSSERVER from
RADPOOL where
POOL='Carrefour' and STATE=0 order by TIME_STAMP
Thu Sep 28 09:13:39 2000: DEBUG: do query is: update RADPOOL set STATE=1,
TIME_STAMP=970125219,
EXPIRY=970211619, USERNAME='carrefour' where YIADDR='10.69.1.51'
Thu Sep 28 09:13:39 2000: DEBUG: Access accepted for carrefour
Thu Sep 28 09:13:39 2000: DEBUG: Packet dump:
*** Sending to 10.69.1.1 port 1645 ....
Code: Access-Accept
Identifier: 69
Authentic: <236><0><24>fp<228><142>1<192>F<129><134><19><205>g<162>
Attributes:
Service-Type = Framed-User
Framed-IP-Netmask = 255.255.255.0
Framed-IP-Address = 10.69.1.51
Thu Sep 28 09:13:39 2000: DEBUG: Packet dump:
*** Received from 10.69.1.1 port 1646 ....
Code: Accounting-Request
Identifier: 70
Authentic: <20>.S<30><137>^,<239>]j<198>&<139>/<193><240>
Attributes:
NAS-IP-Address = 10.69.1.1
NAS-Port = 20
NAS-Port-Type = Async
User-Name = "Carrefour"
Called-Station-Id = "6641"
Calling-Station-Id = "608715017"
Acct-Status-Type = Start
Acct-Authentic = RADIUS
Service-Type = Framed-User
Acct-Session-Id = "0000015A"
Framed-Protocol = PPP
Acct-Delay-Time = 0
Thu Sep 28 09:13:39 2000: DEBUG: Rewrote user name to carrefour
Thu Sep 28 09:13:39 2000: DEBUG: Check if Handler should be used to handle this
request
Thu Sep 28 09:13:39 2000: DEBUG: Handling request with Handler ''
Thu Sep 28 09:13:39 2000: DEBUG: SDBSQL Adding session for Carrefour, 10.69.1.1, 20
Thu Sep 28 09:13:39 2000: DEBUG: do query is: delete from ONLINE where
USERNAME='carrefour' and NASPORT=20
Thu Sep 28 09:13:39 2000: DEBUG: do query is: insert into ONLINE (USERNAME,
NASIDENTIFIER, NASPORT, ACCTSESSIONID, TIME_STAMP, FRAMEDIPADDRESS, CALLINGID,
CALLEDID) values ('carrefour', '10.69.1.1', 20, '0000015A', 970125219, '', 608715017,
6641 )
Thu Sep 28 09:13:39 2000: DEBUG: Handling with Radius::AuthSQL
Thu Sep 28 09:13:39 2000: DEBUG: Handling accounting with Radius::AuthSQL
Thu Sep 28 09:13:39 2000: DEBUG: Handling with Radius::AuthSQL
Thu Sep 28 09:13:39 2000: DEBUG: Handling accounting with Radius::AuthSQL
Thu Sep 28 09:13:39 2000: DEBUG: Handling with Radius::AuthDYNADDRESS
Thu Sep 28 09:13:39 2000: DEBUG: Accounting accepted
Thu Sep 28 09:13:39 2000: DEBUG: Packet dump:
*** Sending to 10.69.1.1 port 1646 ....
Code: Accounting-Response
Identifier: 70
Authentic: <20>.S<30><137>^,<239>]j<198>&<139>/<193><240>
Attributes:
Thu Sep 28 09:13:43 2000: DEBUG: Packet dump:
*** Received from 10.69.1.1 port 1645 ....
Code: Access-Request
Identifier: 71
Authentic: "<189>P<226><212><156>q.<192>F<129><134>y<8><208>9
Attributes:
NAS-IP-Address = 10.69.1.1
NAS-Port = 20
NAS-Port-Type = Async
User-Name = "Carrefour"
Called-Station-Id = "6641"
Calling-Station-Id = "608715017"
CHAP-Password = "<10><21>k<197>qo<180>P<132><225>QG<204><197><131><199><205>"
Service-Type = Framed-User
Framed-Protocol = PPP
Thu Sep 28 09:13:43 2000: DEBUG: Rewrote user name to carrefour
Thu Sep 28 09:13:43 2000: DEBUG: Check if Handler should be used to handle this
request
Thu Sep 28 09:13:43 2000: DEBUG: Handling request with Handler ''
Thu Sep 28 09:13:43 2000: DEBUG: SDBSQL Deleting session for Carrefour, 10.69.1.1, 20
Thu Sep 28 09:13:43 2000: DEBUG: do query is: delete from ONLINE where
USERNAME='carrefour' and NASPORT=20
Thu Sep 28 09:13:43 2000: DEBUG: Handling with Radius::AuthSQL
Thu Sep 28 09:13:43 2000: DEBUG: Handling with Radius::AuthSQL
Thu Sep 28 09:13:43 2000: DEBUG: Query is: select PASSWORD, CHECKATTR, REPLYATTR from
SUBSCRIBERS where USERNAME = 'carrefour'
Thu Sep 28 09:13:43 2000: DEBUG: Radius::AuthSQL looks for match with carrefour
Thu Sep 28 09:13:43 2000: DEBUG: Radius::AuthSQL ACCEPT:
Thu Sep 28 09:13:43 2000: DEBUG: Handling with Radius::AuthSQL
Thu Sep 28 09:13:43 2000: DEBUG: Handling with Radius::AuthSQL
Thu Sep 28 09:13:43 2000: DEBUG: Query is: select NULL, CHECKATTR, REPLYATTR from
SUBSCRIBERS where USERNAME = 'DEFAULT'
Thu Sep 28 09:13:43 2000: DEBUG: Radius::AuthSQL looks for match with carrefour
Thu Sep 28 09:13:43 2000: DEBUG: Radius::AuthSQL ACCEPT:
Thu Sep 28 09:13:43 2000: DEBUG: Handling with Radius::AuthDYNADDRESS
Thu Sep 28 09:13:43 2000: DEBUG: Query is: select YIADDR, SUBNETMASK, DNSSERVER from
RADPOOL where
POOL='Carrefour' and STATE=0 order by TIME_STAMP
Thu Sep 28 09:13:43 2000: DEBUG: do query is: update RADPOOL set STATE=1,
TIME_STAMP=970125223,
EXPIRY=970211623, USERNAME='carrefour' where YIADDR='10.69.1.49'
Thu Sep 28 09:13:43 2000: DEBUG: Access accepted for carrefour
Thu Sep 28 09:13:43 2000: DEBUG: Packet dump:
*** Sending to 10.69.1.1 port 1645 ....
Code: Access-Accept
Identifier: 71
Authentic: "<189>P<226><212><156>q.<192>F<129><134>y<8><208>9
Attributes:
Service-Type = Framed-User
Framed-IP-Netmask = 255.255.255.0
Framed-IP-Address = 10.69.1.49
Thu Sep 28 09:13:43 2000: DEBUG: Packet dump:
*** Received from 10.69.1.1 port 1646 ....
Code: Accounting-Request
Identifier: 72
Authentic: <243>J<225><227>E<244>4c<173>aX<142><152>8<172>q
Attributes:
NAS-IP-Address = 10.69.1.1
NAS-Port = 20
NAS-Port-Type = Async
User-Name = "Carrefour"
Called-Station-Id = "6641"
Calling-Station-Id = "608715017"
Acct-Status-Type = Stop
Acct-Authentic = RADIUS
Service-Type = Framed-User
Acct-Session-Id = "0000015A"
Framed-Protocol = PPP
Acct-Input-Octets = 294
Acct-Output-Octets = 153
Acct-Input-Packets = 9
Acct-Output-Packets = 8
Acct-Session-Time = 4
Acct-Delay-Time = 0
Thu Sep 28 09:13:43 2000: DEBUG: Rewrote user name to carrefour
Thu Sep 28 09:13:43 2000: DEBUG: Check if Handler should be used to handle this
request
Thu Sep 28 09:13:43 2000: DEBUG: Handling request with Handler ''
Thu Sep 28 09:13:43 2000: DEBUG: SDBSQL Deleting session for Carrefour, 10.69.1.1, 20
Thu Sep 28 09:13:43 2000: DEBUG: do query is: delete from ONLINE where
USERNAME='carrefour' and NASPORT=20
Thu Sep 28 09:13:43 2000: DEBUG: Handling with Radius::AuthSQL
Thu Sep 28 09:13:43 2000: DEBUG: Handling accounting with Radius::AuthSQL
Thu Sep 28 09:13:43 2000: DEBUG: Handling with Radius::AuthSQL
Thu Sep 28 09:13:43 2000: DEBUG: Handling accounting with Radius::AuthSQL
Thu Sep 28 09:13:43 2000: DEBUG: do query is: insert into 2000_09_28
(USERNAME, TIME_STAMP, ACCTSTATUSTYPE, ACCTDELAYTIME, ACCTINPUTOCTETS,
ACCTOUTPUTOCTETS, ACCTSESSIONID, ACCTSESSIONTIME, NASPORT, CALLINGID, CALLEDID)
values
('carrefour', 970125223, 'Stop', 0, 294, 153, '0000015A', 4, 20,
'608715017', '6641')
Thu Sep 28 09:13:43 2000: DEBUG: Handling with Radius::AuthDYNADDRESS
Thu Sep 28 09:13:43 2000: DEBUG: do query is: update RADPOOL set STATE=0,
TIME_STAMP=970125223
where YIADDR=''
Thu Sep 28 09:13:43 2000: DEBUG: Accounting accepted
Thu Sep 28 09:13:43 2000: DEBUG: Packet dump:
*** Sending to 10.69.1.1 port 1646 ....
Code: Accounting-Response
Identifier: 72
Authentic: <243>J<225><227>E<244>4c<173>aX<142><152>8<172>q
Attributes:
Thu Sep 28 09:13:43 2000: DEBUG: Packet dump:
*** Received from 10.69.1.1 port 1646 ....
Code: Accounting-Request
Identifier: 73
Authentic: <171>`<191><205><179><157><216>_p%<143>@<196><235>5<240>
Attributes:
NAS-IP-Address = 10.69.1.1
NAS-Port = 20
NAS-Port-Type = Async
User-Name = "Carrefour"
Called-Station-Id = "6641"
Calling-Station-Id = "608715017"
Acct-Status-Type = Start
Acct-Authentic = RADIUS
Service-Type = Framed-User
Acct-Session-Id = "0000015B"
Framed-Protocol = PPP
Acct-Delay-Time = 0
Thu Sep 28 09:13:43 2000: DEBUG: Rewrote user name to carrefour
Thu Sep 28 09:13:43 2000: DEBUG: Check if Handler should be used to handle this
request
Thu Sep 28 09:13:43 2000: DEBUG: Handling request with Handler ''
Thu Sep 28 09:13:43 2000: DEBUG: SDBSQL Adding session for Carrefour, 10.69.1.1, 20
Thu Sep 28 09:13:43 2000: DEBUG: do query is: delete from ONLINE where
USERNAME='carrefour' and NASPORT=20
Thu Sep 28 09:13:43 2000: DEBUG: do query is: insert into ONLINE (USERNAME,
NASIDENTIFIER, NASPORT, ACCTSESSIONID, TIME_STAMP, FRAMEDIPADDRESS, CALLINGID,
CALLEDID) values ('carrefour', '10.69.1.1', 20, '0000015B', 970125223, '', 608715017,
6641 )
Thu Sep 28 09:13:43 2000: DEBUG: Handling with Radius::AuthSQL
Thu Sep 28 09:13:43 2000: DEBUG: Handling accounting with Radius::AuthSQL
Thu Sep 28 09:13:43 2000: DEBUG: Handling with Radius::AuthSQL
Thu Sep 28 09:13:43 2000: DEBUG: Handling accounting with Radius::AuthSQL
Thu Sep 28 09:13:43 2000: DEBUG: Handling with Radius::AuthDYNADDRESS
Thu Sep 28 09:13:43 2000: DEBUG: Accounting accepted
Thu Sep 28 09:13:43 2000: DEBUG: Packet dump:
*** Sending to 10.69.1.1 port 1646 ....
Code: Accounting-Response
Identifier: 73
Authentic: <171>`<191><205><179><157><216>_p%<143>@<196><235>5<240>
Attributes:
Thu Sep 28 09:13:49 2000: DEBUG: Packet dump:
*** Received from 10.69.1.1 port 1645 ....
Code: Access-Request
Identifier: 74
Authentic: _0 <152><217>sD<140><192>F<129><134><9>j<149><225>
Attributes:
NAS-IP-Address = 10.69.1.1
NAS-Port = 11
NAS-Port-Type = Async
User-Name = "Carrefour"
Called-Station-Id = "6641"
Calling-Station-Id = "670487956"
CHAP-Password = "<7><187>"meBU<252><6><15><129>><213><235><26><249><170>"
Service-Type = Framed-User
Framed-Protocol = PPP
Thu Sep 28 09:13:49 2000: DEBUG: Rewrote user name to carrefour
Thu Sep 28 09:13:49 2000: DEBUG: Check if Handler should be used to handle this
request
Thu Sep 28 09:13:49 2000: DEBUG: Handling request with Handler ''
Thu Sep 28 09:13:49 2000: DEBUG: SDBSQL Deleting session for Carrefour, 10.69.1.1, 11
Thu Sep 28 09:13:49 2000: DEBUG: do query is: delete from ONLINE where
USERNAME='carrefour' and NASPORT=11
Thu Sep 28 09:13:49 2000: DEBUG: Handling with Radius::AuthSQL
Thu Sep 28 09:13:49 2000: DEBUG: Handling with Radius::AuthSQL
Thu Sep 28 09:13:49 2000: DEBUG: Query is: select PASSWORD, CHECKATTR, REPLYATTR from
SUBSCRIBERS where USERNAME = 'carrefour'
Thu Sep 28 09:13:49 2000: DEBUG: Radius::AuthSQL looks for match with carrefour
Thu Sep 28 09:13:49 2000: DEBUG: Radius::AuthSQL ACCEPT:
Thu Sep 28 09:13:49 2000: DEBUG: Handling with Radius::AuthSQL
Thu Sep 28 09:13:49 2000: DEBUG: Handling with Radius::AuthSQL
Thu Sep 28 09:13:49 2000: DEBUG: Query is: select NULL, CHECKATTR, REPLYATTR from
SUBSCRIBERS where USERNAME = 'DEFAULT'
Thu Sep 28 09:13:49 2000: DEBUG: Radius::AuthSQL looks for match with carrefour
Thu Sep 28 09:13:49 2000: DEBUG: Radius::AuthSQL ACCEPT:
Thu Sep 28 09:13:49 2000: DEBUG: Handling with Radius::AuthDYNADDRESS
Thu Sep 28 09:13:49 2000: DEBUG: Query is: select YIADDR, SUBNETMASK, DNSSERVER from
RADPOOL where
POOL='Carrefour' and STATE=0 order by TIME_STAMP
Thu Sep 28 09:13:49 2000: DEBUG: do query is: update RADPOOL set STATE=1,
TIME_STAMP=970125229,
EXPIRY=970211629, USERNAME='carrefour' where YIADDR='10.69.1.42'
Thu Sep 28 09:13:49 2000: DEBUG: Access accepted for carrefour
Thu Sep 28 09:13:49 2000: DEBUG: Packet dump:
*** Sending to 10.69.1.1 port 1645 ....
Code: Access-Accept
Identifier: 74
Authentic: _0 <152><217>sD<140><192>F<129><134><9>j<149><225>
Attributes:
Service-Type = Framed-User
Framed-IP-Netmask = 255.255.255.0
Framed-IP-Address = 10.69.1.42
Thu Sep 28 09:13:49 2000: DEBUG: Packet dump:
*** Received from 10.69.1.1 port 1646 ....
Code: Accounting-Request
Identifier: 75
Authentic: -<197><223>n<236>J3K3<172><246>*0<138><145>G
Attributes:
NAS-IP-Address = 10.69.1.1
NAS-Port = 11
NAS-Port-Type = Async
User-Name = "Carrefour"
Called-Station-Id = "6641"
Calling-Station-Id = "670487956"
Acct-Status-Type = Start
Acct-Authentic = RADIUS
Service-Type = Framed-User
Acct-Session-Id = "0000015C"
Framed-Protocol = PPP
Acct-Delay-Time = 0
Thu Sep 28 09:13:49 2000: DEBUG: Rewrote user name to carrefour
Thu Sep 28 09:13:49 2000: DEBUG: Check if Handler should be used to handle this
request
Thu Sep 28 09:13:49 2000: DEBUG: Handling request with Handler ''
Thu Sep 28 09:13:49 2000: DEBUG: SDBSQL Adding session for Carrefour, 10.69.1.1, 11
Thu Sep 28 09:13:49 2000: DEBUG: do query is: delete from ONLINE where
USERNAME='carrefour' and NASPORT=11
Thu Sep 28 09:13:49 2000: DEBUG: do query is: insert into ONLINE (USERNAME,
NASIDENTIFIER, NASPORT, ACCTSESSIONID, TIME_STAMP, FRAMEDIPADDRESS, CALLINGID,
CALLEDID) values ('carrefour', '10.69.1.1', 11, '0000015C', 970125229, '', 670487956,
6641 )
Thu Sep 28 09:13:49 2000: DEBUG: Handling with Radius::AuthSQL
Thu Sep 28 09:13:49 2000: DEBUG: Handling accounting with Radius::AuthSQL
Thu Sep 28 09:13:49 2000: DEBUG: Handling with Radius::AuthSQL
Thu Sep 28 09:13:49 2000: DEBUG: Handling accounting with Radius::AuthSQL
Thu Sep 28 09:13:49 2000: DEBUG: Handling with Radius::AuthDYNADDRESS
Thu Sep 28 09:13:49 2000: DEBUG: Accounting accepted
Thu Sep 28 09:13:49 2000: DEBUG: Packet dump:
*** Sending to 10.69.1.1 port 1646 ....
Code: Accounting-Response
Identifier: 75
Authentic: -<197><223>n<236>J3K3<172><246>*0<138><145>G
Attributes:
Thu Sep 28 09:13:51 2000: DEBUG: Packet dump:
*** Received from 10.69.1.1 port 1646 ....
Code: Accounting-Request
Identifier: 76
Authentic: <251>y<1>_Ab<195><6><152><31><128><154><128><235><193>N
Attributes:
NAS-IP-Address = 10.69.1.1
NAS-Port = 11
NAS-Port-Type = Async
User-Name = "Carrefour"
Called-Station-Id = "6641"
Calling-Station-Id = "670487956"
Acct-Status-Type = Alive
Acct-Authentic = RADIUS
Service-Type = Framed-User
Acct-Session-Id = "0000015C"
Framed-Protocol = PPP
Framed-IP-Address = 10.69.1.42
Acct-Delay-Time = 0
Thu Sep 28 09:13:51 2000: DEBUG: Rewrote user name to carrefour
Thu Sep 28 09:13:51 2000: DEBUG: Check if Handler should be used to handle this
request
Thu Sep 28 09:13:51 2000: DEBUG: Handling request with Handler ''
Thu Sep 28 09:13:51 2000: DEBUG: SDBSQL Adding session for Carrefour, 10.69.1.1, 11
Thu Sep 28 09:13:51 2000: DEBUG: do query is: delete from ONLINE where
USERNAME='carrefour' and NASPORT=11
Thu Sep 28 09:13:51 2000: DEBUG: do query is: insert into ONLINE (USERNAME,
NASIDENTIFIER, NASPORT, ACCTSESSIONID, TIME_STAMP, FRAMEDIPADDRESS, CALLINGID,
CALLEDID) values ('carrefour', '10.69.1.1', 11, '0000015C', 970125231, '10.69.1.42',
670487956, 6641 )
Thu Sep 28 09:13:51 2000: DEBUG: Handling with Radius::AuthSQL
Thu Sep 28 09:13:51 2000: DEBUG: Handling accounting with Radius::AuthSQL
Thu Sep 28 09:13:51 2000: DEBUG: Handling with Radius::AuthSQL
Thu Sep 28 09:13:51 2000: DEBUG: Handling accounting with Radius::AuthSQL
Thu Sep 28 09:13:51 2000: DEBUG: Handling with Radius::AuthDYNADDRESS
Thu Sep 28 09:13:51 2000: DEBUG: Accounting accepted
Thu Sep 28 09:13:51 2000: DEBUG: Packet dump:
*** Sending to 10.69.1.1 port 1646 ....
Code: Accounting-Response
Identifier: 76
Authentic: <251>y<1>_Ab<195><6><152><31><128><154><128><235><193>N
Attributes:
Thu Sep 28 09:15:51 2000: DEBUG: Packet dump:
*** Received from 10.69.1.1 port 1646 ....
Code: Accounting-Request
Identifier: 77
Authentic: <247><248><4><180>ZI<222><204>{T/<141><213>e<241>)
Attributes:
NAS-IP-Address = 10.69.1.1
NAS-Port = 11
NAS-Port-Type = Async
User-Name = "Carrefour"
Called-Station-Id = "6641"
Calling-Station-Id = "670487956"
Acct-Status-Type = Stop
Acct-Authentic = RADIUS
Service-Type = Framed-User
Acct-Session-Id = "0000015C"
Framed-Protocol = PPP
Framed-IP-Address = 10.69.1.42
Acct-Terminate-Cause = User-Request
Acct-Input-Octets = 554
Acct-Output-Octets = 1506
Acct-Input-Packets = 17
Acct-Output-Packets = 13
Acct-Session-Time = 122
Acct-Delay-Time = 0
Thu Sep 28 09:15:51 2000: DEBUG: Rewrote user name to carrefour
Thu Sep 28 09:15:51 2000: DEBUG: Check if Handler should be used to handle this
request
Thu Sep 28 09:15:51 2000: DEBUG: Handling request with Handler ''
Thu Sep 28 09:15:51 2000: DEBUG: SDBSQL Deleting session for Carrefour, 10.69.1.1, 11
Thu Sep 28 09:15:51 2000: DEBUG: do query is: delete from ONLINE where
USERNAME='carrefour' and NASPORT=11
Thu Sep 28 09:15:51 2000: DEBUG: Handling with Radius::AuthSQL
Thu Sep 28 09:15:51 2000: DEBUG: Handling accounting with Radius::AuthSQL
Thu Sep 28 09:15:51 2000: DEBUG: Handling with Radius::AuthSQL
Thu Sep 28 09:15:51 2000: DEBUG: Handling accounting with Radius::AuthSQL
Thu Sep 28 09:15:51 2000: DEBUG: do query is: insert into 2000_09_28
(USERNAME, TIME_STAMP, ACCTSTATUSTYPE, ACCTDELAYTIME, ACCTINPUTOCTETS,
ACCTOUTPUTOCTETS, ACCTSESSIONID, ACCTSESSIONTIME, NASPORT, FRAMEDIPADDRESS, CALLINGID,
CALLEDID)
values
('carrefour', 970125351, 'Stop', 0, 554, 1506, '0000015C', 122, 11,
'10.69.1.42', '670487956', '6641')
Thu Sep 28 09:15:51 2000: DEBUG: Handling with Radius::AuthDYNADDRESS
Thu Sep 28 09:15:51 2000: DEBUG: do query is: update RADPOOL set STATE=0,
TIME_STAMP=970125351
where YIADDR='10.69.1.42'
Thu Sep 28 09:15:51 2000: DEBUG: Accounting accepted
Thu Sep 28 09:15:51 2000: DEBUG: Packet dump:
*** Sending to 10.69.1.1 port 1646 ....
Code: Accounting-Response
Identifier: 77
Authentic: <247><248><4><180>ZI<222><204>{T/<141><213>e<241>)
Attributes:
Thu Sep 28 09:16:01 2000: DEBUG: Packet dump:
*** Received from 10.69.1.1 port 1646 ....
Code: Accounting-Request
Identifier: 78
Authentic: <24><233><194><140><140><194><254><132><206>'><132><154>{<151><207>
Attributes:
NAS-IP-Address = 10.69.1.1
NAS-Port = 20
NAS-Port-Type = Async
User-Name = "Carrefour"
Called-Station-Id = "6641"
Calling-Station-Id = "608715017"
Acct-Status-Type = Stop
Acct-Authentic = RADIUS
Service-Type = Framed-User
Acct-Session-Id = "0000015B"
Framed-Protocol = PPP
Acct-Terminate-Cause = Lost-Carrier
Acct-Input-Octets = 1264
Acct-Output-Octets = 162
Acct-Input-Packets = 20
Acct-Output-Packets = 12
Acct-Session-Time = 138
Acct-Delay-Time = 0
Thu Sep 28 09:16:01 2000: DEBUG: Rewrote user name to carrefour
Thu Sep 28 09:16:01 2000: DEBUG: Check if Handler should be used to handle this
request
Thu Sep 28 09:16:01 2000: DEBUG: Handling request with Handler ''
Thu Sep 28 09:16:01 2000: DEBUG: SDBSQL Deleting session for Carrefour, 10.69.1.1, 20
Thu Sep 28 09:16:01 2000: DEBUG: do query is: delete from ONLINE where
USERNAME='carrefour' and NASPORT=20
Thu Sep 28 09:16:01 2000: DEBUG: Handling with Radius::AuthSQL
Thu Sep 28 09:16:01 2000: DEBUG: Handling accounting with Radius::AuthSQL
Thu Sep 28 09:16:01 2000: DEBUG: Handling with Radius::AuthSQL
Thu Sep 28 09:16:01 2000: DEBUG: Handling accounting with Radius::AuthSQL
Thu Sep 28 09:16:01 2000: DEBUG: do query is: insert into 2000_09_28
(USERNAME, TIME_STAMP, ACCTSTATUSTYPE, ACCTDELAYTIME, ACCTINPUTOCTETS,
ACCTOUTPUTOCTETS, ACCTSESSIONID, ACCTSESSIONTIME, NASPORT, CALLINGID, CALLEDID)
values
('carrefour', 970125361, 'Stop', 0, 1264, 162, '0000015B', 138, 20,
'608715017', '6641')
Thu Sep 28 09:16:01 2000: DEBUG: Handling with Radius::AuthDYNADDRESS
Thu Sep 28 09:16:01 2000: DEBUG: do query is: update RADPOOL set STATE=0,
TIME_STAMP=970125361
where YIADDR=''
Thu Sep 28 09:16:01 2000: DEBUG: Accounting accepted
Thu Sep 28 09:16:01 2000: DEBUG: Packet dump:
*** Sending to 10.69.1.1 port 1646 ....
Code: Accounting-Response
Identifier: 78
Authentic: <24><233><194><140><140><194><254><132><206>'><132><154>{<151><207>
Attributes: