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: