[RADIATOR] Fail to Call radpwtst From Hook File
Mustofa Haykal
mustofa at kccg.com
Wed Sep 6 09:41:15 UTC 2017
Hi Hugh,
Thank you for the advice. I take another way to get rid of that error log, by defining the 'BindAddress' to the current radiator address.
Here is the log after system reboot:
https://www.open.com.au/ordering.html
To extend your license period, contact info at open.com.au
Wed Sep 6 11:41:51 2017: DEBUG: Reading dictionary file '/opt/radiator/current/dictionary'
Wed Sep 6 11:41:51 2017: INFO: Using Net::SSLeay 1.68 with SSL/TLS library version 0x1000105f (OpenSSL 1.0.1e-fips 11 Feb 2013)
Wed Sep 6 11:41:51 2017: DEBUG: This system is IPv6 capable. IPv6 capability provided by: core
Wed Sep 6 11:41:51 2017: DEBUG: Creating authentication port 172.16.0.199:1645
Wed Sep 6 11:41:51 2017: DEBUG: Creating authentication port 172.16.0.199:1812
Wed Sep 6 11:41:51 2017: DEBUG: Creating accounting port 172.16.0.199:1646
Wed Sep 6 11:41:51 2017: DEBUG: Creating accounting port 172.16.0.199:1813
Wed Sep 6 11:41:51 2017: NOTICE: Server started: Radiator 4.19 on radiator (LOCKED)
However, I still facing the same issue. I can't make the hook file work as it should be.
Here the brief of RADUSERS table when I try to authenticate:
OCTETSINLEFT OCTETSOUTLEFT USERNAME VALIDFROM VALIDTO
NULL 78649202 vodar 1502889360 1534377600
Here's the authentication log:
Wed Sep 6 11:48:48 2017: DEBUG: Packet dump:
*** Received from 172.16.0.240 port 33013 ....
Code: Access-Request
Identifier: 91
Authentic: <234><151><133><209><31><224><156><130><130>y<153><194><171><235>e<188>
Attributes:
User-Name = "vodar"
CHAP-Password = <202>"I<242><189><176>y<216><245>8Ry<0><255><204><193><187>
NAS-Identifier = "F8-E7-1E-07-1D-20"
NAS-IP-Address = 172.16.0.189
Framed-IP-Address = 172.16.0.198
Called-Station-Id = "f8-e7-1e-07-1d-20:ruckus-web-auth"
Service-Type = Login-User
Calling-Station-Id = "b4-6d-83-76-f2-91"
NAS-Port-Type = Wireless-IEEE-802-11
Ruckus-SSID = "ruckus-web-auth"
Ruckus-Zone-Name = "kccg-office"
Ruckus-Wlan-Name = "ruckus-web-auth"
Ruckus-BSSID = <248><231><30><7><29>,
Message-Authenticator = <201>^<142><182><252><211><250>c<8><236><187>\<245><131>A<16>
CHAP-Challenge = <214><157> q<255>*<25><202>3W<207><211>b<161>Y<127>
Chargeable-User-Identity = <0>
Proxy-State = 102
Wed Sep 6 11:48:48 2017: DEBUG: Handling request with Handler 'Realm=', Identifier ''
Wed Sep 6 11:48:48 2017: DEBUG: OnlineUsers Deleting session for vodar, 172.16.0.189, 0
Wed Sep 6 11:48:48 2017: DEBUG: Connecting to 'dbi:mysql:radmin:localhost Connection id: 0-00000'
Wed Sep 6 11:48:49 2017: DEBUG: do query to 'dbi:mysql:radmin:localhost Connection id: 0-00000': 'delete from RADONLINE where NASIDENTIFIER='172.16.0.189' and NASPORT=00':
Wed Sep 6 11:48:49 2017: DEBUG: Query to 'dbi:mysql:radmin:localhost Connection id: 0-00000': 'select NASIDENTIFIER, NASPORT, ACCTSESSIONID, FRAMEDIPADDRESS from RADONLINE where USERNAME='vodar'':
Wed Sep 6 11:48:49 2017: DEBUG: Handling with Radius::AuthSQL: SQL-acct
Wed Sep 6 11:48:49 2017: DEBUG: Handling with Radius::AuthSQL: SQL-acct
Wed Sep 6 11:48:49 2017: DEBUG: Query to 'dbi:mysql:radmin:localhost Connection id: 0-00000': 'select PASSWORD from SUBSCRIBERS where USERNAME='vodar'':
Wed Sep 6 11:48:49 2017: ERR: Execute failed for 'select PASSWORD from SUBSCRIBERS where USERNAME='vodar'': Table 'radmin.SUBSCRIBERS' doesn't exist
Wed Sep 6 11:48:49 2017: DEBUG: Connecting to 'dbi:mysql:radmin:localhost Connection id: 0-00000'
Wed Sep 6 11:48:49 2017: DEBUG: Query to 'dbi:mysql:radmin:localhost Connection id: 0-00000': 'select PASSWORD from SUBSCRIBERS where USERNAME='vodar'':
Wed Sep 6 11:48:49 2017: ERR: Execute failed for 'select PASSWORD from SUBSCRIBERS where USERNAME='vodar'': Table 'radmin.SUBSCRIBERS' doesn't exist
Wed Sep 6 11:48:49 2017: DEBUG: Radius::AuthSQL looks for match with vodar [vodar]
Wed Sep 6 11:48:49 2017: DEBUG: Radius::AuthSQL REJECT: No such user: vodar [vodar]
Wed Sep 6 11:48:49 2017: DEBUG: Connecting to 'dbi:mysql:radmin:localhost Connection id: 0-00000'
Wed Sep 6 11:48:49 2017: DEBUG: Query to 'dbi:mysql:radmin:localhost Connection id: 0-00000': 'select PASSWORD from SUBSCRIBERS where USERNAME='DEFAULT'':
Wed Sep 6 11:48:49 2017: ERR: Execute failed for 'select PASSWORD from SUBSCRIBERS where USERNAME='DEFAULT'': Table 'radmin.SUBSCRIBERS' doesn't exist
Wed Sep 6 11:48:49 2017: DEBUG: Connecting to 'dbi:mysql:radmin:localhost Connection id: 0-00000'
Wed Sep 6 11:48:49 2017: DEBUG: Query to 'dbi:mysql:radmin:localhost Connection id: 0-00000': 'select PASSWORD from SUBSCRIBERS where USERNAME='DEFAULT'':
Wed Sep 6 11:48:49 2017: ERR: Execute failed for 'select PASSWORD from SUBSCRIBERS where USERNAME='DEFAULT'': Table 'radmin.SUBSCRIBERS' doesn't exist
Wed Sep 6 11:48:49 2017: DEBUG: AuthBy SQL result: REJECT, No such user
Wed Sep 6 11:48:49 2017: DEBUG: Handling with Radius::AuthSQL: SQL-auth
Wed Sep 6 11:48:49 2017: DEBUG: Handling with Radius::AuthSQL: SQL-auth
Wed Sep 6 11:48:49 2017: DEBUG: Connecting to 'dbi:mysql:radmin:localhost Connection id: 0-00000'
Wed Sep 6 11:48:49 2017: DEBUG: Query to 'dbi:mysql:radmin:localhost Connection id: 0-00000': 'select PASS_WORD, OCTETSOUTLEFT from RADUSERS where USERNAME='vodar' and OCTETSOUTLEFT > 0':
Wed Sep 6 11:48:49 2017: DEBUG: Radius::AuthSQL looks for match with vodar [vodar]
Wed Sep 6 11:48:49 2017: DEBUG: Radius::AuthSQL ACCEPT: : vodar [vodar]
Wed Sep 6 11:48:49 2017: DEBUG: AuthBy SQL result: ACCEPT,
Wed Sep 6 11:48:49 2017: DEBUG: Access accepted for vodar
Wed Sep 6 11:48:49 2017: ERR: There is no value named Framed for attribute Service-Type. Using 0.
Wed Sep 6 11:48:49 2017: DEBUG: Packet dump:
*** Sending to 172.16.0.240 port 33013 ....
Code: Access-Accept
Identifier: 91
Authentic: <228><231>I<240><19><132><201>iz<227><176>4a&<223>b
Attributes:
Service-Type = Framed
Framed-Protocol = PPP
Proxy-State = 102
Message-Authenticator = <0><0><0><0><0><0><0><0><0><0><0><0><0><0><0><0>
And here the brief of RADUSERS table when it should be disconnected: (interim update per 1 minute)
OCTETSINLEFT OCTETSOUTLEFT USERNAME VALIDFROM VALIDTO
NULL -3678649202 vodar 1502889360 1534377600
Here's the log:
Wed Sep 6 11:48:49 2017: DEBUG: Packet dump:
*** Received from 172.16.0.189 port 44955 ....
Code: Accounting-Request
Identifier: 13
Authentic: <219>C,<162>6<2>Py+<29><199><140><199><219>L<142>
Attributes:
Acct-Session-Id = "59AFB639-071D2000"
Framed-IP-Address = 172.16.0.198
Acct-Multi-Session-Id = "f8e71e071d2cb46d8376f29159afb6390057"
Acct-Link-Count = 1
Acct-Status-Type = Start
Acct-Authentic = RADIUS
User-Name = "vodar"
NAS-IP-Address = 172.16.0.189
NAS-Identifier = "F8-E7-1E-07-1D-20"
NAS-Port = 1
Called-Station-Id = "F8-E7-1E-07-1D-20:ruckus-web-auth"
Calling-Station-Id = "B4-6D-83-76-F2-91"
NAS-Port-Type = Wireless-IEEE-802-11
Connect-Info = "CONNECT 802.11a/n/ac"
Event-Timestamp = 1504687683
Ruckus-SSID = "ruckus-web-auth"
Ruckus-BSSID = <248><231><30><7><29>,
Ruckus-Wlan-Id = 1
Ruckus-Sta-Vlan-Id = 1
Ruckus-SCG-CBlade-IP = 2886729968
Wed Sep 6 11:48:49 2017: DEBUG: Handling request with Handler 'Realm=', Identifier ''
Wed Sep 6 11:48:49 2017: DEBUG: OnlineUsers Adding session for vodar, 172.16.0.189, 1
Wed Sep 6 11:48:49 2017: DEBUG: OnlineUsers Deleting session for vodar, 172.16.0.189, 1
Wed Sep 6 11:48:49 2017: DEBUG: do query to 'dbi:mysql:radmin:localhost Connection id: 0-00000': 'delete from RADONLINE where NASIDENTIFIER='172.16.0.189' and NASPORT=01':
Wed Sep 6 11:48:49 2017: DEBUG: do query to 'dbi:mysql:radmin:localhost Connection id: 0-00000': 'insert into RADONLINE (USERNAME, NASIDENTIFIER, NASPORT, ACCTSESSIONID, TIME_STAMP, FRAMEDIPADDRESS, SERVICETYPE, CALLINGSTATIONID) values ('vodar', '172.16.0.189', 1, '59AFB639-071D2000', 1504687729, '172.16.0.198', '', 'B4-6D-83-76-F2-91')':
Wed Sep 6 11:48:49 2017: DEBUG: Handling with Radius::AuthSQL: SQL-acct
Wed Sep 6 11:48:49 2017: DEBUG: Handling accounting with Radius::AuthSQL
Wed Sep 6 11:48:49 2017: DEBUG: do query to 'dbi:mysql:radmin:localhost Connection id: 0-00000': 'update RADUSERS set TIMELEFT=TIMELEFT-0, OCTETSINLEFT=OCTETSINLEFT-0,OCTETSOUTLEFT=OCTETSOUTLEFT-0 where USERNAME='vodar'':
Wed Sep 6 11:48:49 2017: DEBUG: do query to 'dbi:mysql:radmin:localhost Connection id: 0-00000': 'insert into RADUSAGE (ACCTSESSIONID,ACCTSTATUSTYPE,CALLINGSTATIONID,DNIS,FRAMEDIPADDRESS,NASIDENTIFIER,NASPORT,TIME_STAMP,USERNAME) values ('59AFB639-071D2000',1,'B4-6D-83-76-F2-91','F8-E7-1E-07-1D-20:ruckus-web-auth','172.16.0.198','F8-E7-1E-07-1D-20',1,1504687729,'vodar')':
Wed Sep 6 11:48:49 2017: DEBUG: AuthBy SQL result: ACCEPT,
Wed Sep 6 11:48:49 2017: DEBUG: Accounting accepted
Wed Sep 6 11:48:49 2017: DEBUG: Packet dump:
*** Sending to 172.16.0.189 port 44955 ....
Code: Accounting-Response
Identifier: 13
Authentic: <210>[<230>c/<203>R<134><172><153>gn<237><248>('
Attributes:
.
.
.
SKIP
.
.
.
Wed Sep 6 12:13:49 2017: DEBUG: Packet dump:
*** Received from 172.16.0.189 port 44955 ....
Code: Accounting-Request
Identifier: 38
Authentic: <18>2H<31><22><140><13><211><16>[(p<196><174><211>J
Attributes:
Acct-Session-Id = "59AFB639-071D2000"
Framed-IP-Address = 172.16.0.198
Acct-Multi-Session-Id = "f8e71e071d2cb46d8376f29159afb6390057"
Acct-Link-Count = 1
Acct-Status-Type = Alive
Acct-Authentic = RADIUS
User-Name = "vodar"
NAS-IP-Address = 172.16.0.189
NAS-Identifier = "F8-E7-1E-07-1D-20"
NAS-Port = 1
Called-Station-Id = "F8-E7-1E-07-1D-20:ruckus-web-auth"
Calling-Station-Id = "B4-6D-83-76-F2-91"
NAS-Port-Type = Wireless-IEEE-802-11
Connect-Info = "CONNECT 802.11a/n/ac"
Event-Timestamp = 1504689183
Ruckus-SSID = "ruckus-web-auth"
Ruckus-BSSID = <248><231><30><7><29>,
Ruckus-Wlan-Id = 1
Ruckus-Sta-Vlan-Id = 1
Ruckus-SCG-CBlade-IP = 2886729968
Acct-Input-Packets = 225886
Acct-Output-Packets = 270928
Acct-Input-Octets = 14864255
Acct-Output-Octets = 366752259
Ruckus-Sta-RSSI = 56
Acct-Session-Time = 1500
Wed Sep 6 12:13:49 2017: DEBUG: Handling request with Handler 'Realm=', Identifier ''
Wed Sep 6 12:13:49 2017: DEBUG: OnlineUsers Adding session for vodar, 172.16.0.189, 1
Wed Sep 6 12:13:49 2017: DEBUG: OnlineUsers Deleting session for vodar, 172.16.0.189, 1
Wed Sep 6 12:13:49 2017: DEBUG: do query to 'dbi:mysql:radmin:localhost Connection id: 0-00000': 'delete from RADONLINE where NASIDENTIFIER='172.16.0.189' and NASPORT=01':
Wed Sep 6 12:13:49 2017: DEBUG: do query to 'dbi:mysql:radmin:localhost Connection id: 0-00000': 'insert into RADONLINE (USERNAME, NASIDENTIFIER, NASPORT, ACCTSESSIONID, TIME_STAMP, FRAMEDIPADDRESS, SERVICETYPE, CALLINGSTATIONID) values ('vodar', '172.16.0.189', 1, '59AFB639-071D2000', 1504689229, '172.16.0.198', '', 'B4-6D-83-76-F2-91')':
Wed Sep 6 12:13:49 2017: DEBUG: Handling with Radius::AuthSQL: SQL-acct
Wed Sep 6 12:13:49 2017: DEBUG: Handling accounting with Radius::AuthSQL
Wed Sep 6 12:13:49 2017: DEBUG: do query to 'dbi:mysql:radmin:localhost Connection id: 0-00000': 'update RADUSERS set TIMELEFT=TIMELEFT-01500, OCTETSINLEFT=OCTETSINLEFT-014864255,OCTETSOUTLEFT=OCTETSOUTLEFT-0366752259 where USERNAME='vodar'':
Wed Sep 6 12:13:49 2017: DEBUG: do query to 'dbi:mysql:radmin:localhost Connection id: 0-00000': 'insert into RADUSAGE (ACCTINPUTOCTETS,ACCTOUTPUTOCTETS,ACCTSESSIONID,ACCTSESSIONTIME,ACCTSTATUSTYPE,CALLINGSTATIONID,DNIS,FRAMEDIPADDRESS,NASIDENTIFIER,NASPORT,TIME_STAMP,USERNAME) values (14864255,366752259,'59AFB639-071D2000',1500,3,'B4-6D-83-76-F2-91','F8-E7-1E-07-1D-20:ruckus-web-auth','172.16.0.198','F8-E7-1E-07-1D-20',1,1504689229,'vodar')':
Wed Sep 6 12:13:49 2017: DEBUG: AuthBy SQL result: ACCEPT,
Wed Sep 6 12:13:49 2017: DEBUG: Accounting accepted
Wed Sep 6 12:13:49 2017: DEBUG: Packet dump:
*** Sending to 172.16.0.189 port 44955 ....
Code: Accounting-Response
Identifier: 38
Authentic: <247><205>e<214>H<128><228>_<136><205><17>lcQ<239><184>
Attributes:
Can you see any miss from my configuration ?
Thank you.
Best Regards,
Mustofa Haykal
System Engineer
Kuwaiti Canadian Consulting Group (www.kccg.com)
T: +965 66576863
F: +965 22415149
E:mustofa at kccg.com
---- Original Message ----
From: "Hugh Irvine" <hugh at open.com.au>
Sent: 9/6/2017 2:03:19 AM
To: "Mustofa Haykal" <mustofa at kccg.com>
Cc: "radiator" <radiator at lists.open.com.au>, "adam" <adam at kccg.com>, "thomas" <thomas at kccg.com>, hvn at open.com.au
Subject: Re: Fail to Call radpwtst From Hook File
Hello Mustofa -
>From the log you show below, you already have an instance of Radiator running on the ports you have defined.
I think you are seeing the log messages from the previously running instance, not the instance you are trying to test.
> Wed Aug 30 17:43:05 2017: DEBUG: Creating authentication port :::1645
> Wed Aug 30 17:43:05 2017: DEBUG: Creating authentication port :::1812
> Wed Aug 30 17:43:05 2017: DEBUG: Creating accounting port :::1646
> Wed Aug 30 17:43:05 2017: DEBUG: Creating accounting port :::1813
> Wed Aug 30 17:43:05 2017: DEBUG: Creating authentication port 0.0.0.0:1645
> Wed Aug 30 17:43:05 2017: ERR: Could not bind authentication socket: Address already in use
> Wed Aug 30 17:43:05 2017: DEBUG: Creating authentication port 0.0.0.0:1812
> Wed Aug 30 17:43:05 2017: ERR: Could not bind authentication socket: Address already in use
> Wed Aug 30 17:43:05 2017: DEBUG: Creating accounting port 0.0.0.0:1646
> Wed Aug 30 17:43:05 2017: ERR: Could not bind accounting socket: Address already in use
> Wed Aug 30 17:43:05 2017: DEBUG: Creating accounting port 0.0.0.0:1813
> Wed Aug 30 17:43:05 2017: ERR: Could not bind accounting socket: Address already in use
You will need to stop the previous instance before trying to run the instance you are trying to test.
The simplest way to do this is to run radiusd in the foreground in a terminal session.
hope that helps
regards
Hugh
> On 5 Sep 2017, at 23:08, Mustofa Haykal <mustofa at kccg.com> wrote:
>
> Hi All,
>
>
> I'm working on WISP project which require Radius AAA. My manager ask me to use Radiator. So we still evaluate this product.
> I create a simple test which will disconnect user session "on the fly" automatically when it exceed the bandwidth quota without waiting the session timeout.
> I'm using Ruckus AP with the VSZ controller as the NAS and install Radiator-Evaluation-4.19-1.ova on VMWare Vsphere.
>
> I removed the default pre-built configuration, and recreate it again based on /goodies references. However I'm still using pre-built "radmin" DB. Successfully done test the Disconnect-Request to the NAS manually and create hook file based on informations from this email group. I put the hook file on the accounting-request handler, so it will check every incoming "alive" packet.
>
> However, I still fail to call the hook file and send the Disconnect-Request automatically when the user exceed the bandwidth usage (I'm using OCTETOUTSLEFT). I see no clue from the logs for this problem.
>
> Here is my radius.cfg along with hook file and latest radiator log.
>
> BindAddress ::,0.0.0.0
> #Foreground
> #LogStdout
>
> DbDir /etc/radiator
> DictionaryFile /opt/radiator/current/dictionary
> LogDir /var/log/radiator
> LogFile %L/radiator-log-%Y-%m
> PidFile /var/run/radiator/radiusd.pid
>
> Trace 4
> AuthPort 1645,1812
> AcctPort 1646,1813
>
> <Client DEFAULT>
> Identifier Client-DEFAULT
> Secret mysecret
> </Client>
> #<Client 168.187.81.1>
> # Secret security
> # DupInterval 300
> #</Client>
>
> <SessionDatabase SQL>
>
>
> Identifier OnlineUsers
> DBSource dbi:mysql:radmin:localhost
> DBUsername radmin
> DBAuth radminpw
> AddQuery insert into RADONLINE \
>
>
> (USERNAME, NASIDENTIFIER, NASPORT, ACCTSESSIONID, TIME_STAMP, FRAMEDIPADDRESS, SERVICETYPE, CALLINGSTATIONID) \
> values \
> ('%n', '%N', %{NAS-Port}, '%{Acct-Session-Id}', %{Timestamp}, '%{Framed-IP-Address}', '%{Service-Type}', '%{Calling-Station-Id}')
>
> </SessionDatabase>
>
> <Realm>
>
> MaxSessions 1
> AuthByPolicy ContinueUntilAccept
>
> <AuthBy SQL>
> Identifier SQL-acct
> DBSource dbi:mysql:radmin:localhost
> DBUsername radmin
> DBAuth radminpw
>
> #AccountingStopsOnly
> AccountingTable RADUSAGE
> AcctColumnDef USERNAME,User-Name
> AcctColumnDef TIME_STAMP,Timestamp,integer
> AcctColumnDef ACCTSTATUSTYPE,Acct-Status-Type,integer
> 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 ACCTTERMINATECAUSE,Acct-Terminate-Cause,integer
> AcctColumnDef FRAMEDIPADDRESS,Framed-IP-Address
> AcctColumnDef NASIDENTIFIER,NAS-IP-Address
> AcctColumnDef NASIDENTIFIER,NAS-Identifier
> AcctColumnDef NASPORT,NAS-Port,integer
> AcctColumnDef DNIS,Called-Station-Id
> AcctColumnDef CALLINGSTATIONID,Calling-Station-Id
>
> AcctSQLStatement update RADUSERS set TIMELEFT=TIMELEFT-0%{Acct-Session-Time}, OCTETSINLEFT=OCTETSINLEFT-0%{Acct-Input-Octets}, OCTETSOUTLEFT=OCTETSOUTLEFT-0%{Acct-Output-Octets} where USERNAME='%n'
>
> </AuthBy>
>
>
>
> <AuthBy SQL>
> Identifier SQL-auth
> DBSource dbi:mysql:radmin:localhost
> DBUsername radmin
> DBAuth radminpw
>
> AuthSelect select PASS_WORD, OCTETSOUTLEFT from RADUSERS where USERNAME='%n' and OCTETSOUTLEFT > 0
>
> AuthColumnDef 0,Password,check
> # AuthColumnDef 1,Session-Timeout,reply
> AddToReply Service-Type = Framed,Framed-Protocol = PPP
> # DefaultReply Service-Type = Framed,Framed-Protocol = PPP
>
> </AuthBy>
>
> <Handler Request-Type="Accounting-Request", Acct-Status-Type = Alive>
> AuthBy SQL-acct
> </Handler>
>
> <Handler>
> # PreAuthHook:"/etc/radiator/DMhook.pl"
> AuthBy SQL-acct
> PostAuthHook file:"/etc/radiator/DMhook.pl"
> </Handler>
> </Realm>
> ---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
>
> Hook File: /etc/radiator/DMhook.pl
>
> use strict;
> use warnings;
> use diagnostics;
>
> sub {
> my $p = ${$_[0]};
>
> return unless $p->code eq 'Accounting-Request';
>
> my $handler = $p->{Handler};
> my $identifier = $handler->{'SQL-acct'};
>
> &main::log($main::LOG_DEBUG, "Running PostAuthHook: Using Identifier $identifier");
>
> # my $user_name = $p->getAttrByNum($Radius::Radius::USER_NAME);
> my $user_name = $p->get_attr('User-Name');
> my $calling_station_id = $p->get_attr('Calling-Station-Id');
> my $sess_handle = Radius::SessGeneric::find($identifier);
> my $query = undef;
>
> main::log($main::LOG_DEBUG, 'Handling Accounting-Request');
>
> $query = "select USERNAME from RADUSERS where OCTETSOUTLEFT <= 0 ";
> my $sth = $sess_handle->prepareAndExecute($query);
> my @row = $sess_handle->getOneRow($sth);
> $sth->finish;
> my $db_user_name = $row[0];
>
> if ( $db_user_name eq $user_name )
> {
> my $sess_id = $p->get_attr('Acct-Session-Id');
> my $framed_ipaddress = $p->get_attr('Framed-IP-Address');
> my @cmd_attrs = ("User-Name=$user_name", "Acct-Session-Id=$sess_id", "Framed-IP-Address=$framed_ipaddress", "Calling-Station-Id=$calling_station_id");
> my @cmd_args = ("-noacct", "-noauth", "-time","-code", "Disconnect-Request");
> push @cmd_args, ("-trace", "4", "-auth_port", "3799", "-s", "172.16.0.240");
> my @cmd = ("perl", "/opt/radiator/current/radpwtst");
>
> main::log($main::LOG_DEBUG, "Running command: @cmd @cmd_args @cmd_attrs");
>
> system (@cmd, @cmd_args, @cmd_attrs);
> }
> }
>
> --------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- Log:
>
> Wed Aug 30 17:42:46 2017: NOTICE: SIGTERM received: stopping
> Wed Aug 30 17:43:05 2017: DEBUG: Finished reading configuration file '/etc/radiator/radiator.cfg'
> Wed Aug 30 17:43:05 2017: WARNING: This Radiator license will expire on 2018-02-01
> Wed Aug 30 17:43:05 2017: WARNING: This Radiator license will stop operating after 1000 requests
> Wed Aug 30 17:43:05 2017: WARNING: To license an unlimited full source version of Radiator, see
> https://www.open.com.au/ordering.html
> To extend your license period, contact info at open.com.au
> Wed Aug 30 17:43:05 2017: DEBUG: Reading dictionary file '/opt/radiator/current/dictionary'
> Wed Aug 30 17:43:05 2017: INFO: Using Net::SSLeay 1.68 with SSL/TLS library version 0x1000105f (OpenSSL 1.0.1e-fips 11 Feb 2013)
> Wed Aug 30 17:43:05 2017: DEBUG: This system is IPv6 capable. IPv6 capability provided by: core
> Wed Aug 30 17:43:05 2017: WARNING: Startup check found OpenSSL version 0x1000105f (OpenSSL 1.0.1e-fips 11 Feb 2013) while checking for the Heartbleed (CVE-2014-0160) vulnerability. This version may be vulnerable. See Radiator reference manual for DisabledRuntimeChecks parameter
> Wed Aug 30 17:43:05 2017: DEBUG: Creating authentication port :::1645
> Wed Aug 30 17:43:05 2017: DEBUG: Creating authentication port :::1812
> Wed Aug 30 17:43:05 2017: DEBUG: Creating accounting port :::1646
> Wed Aug 30 17:43:05 2017: DEBUG: Creating accounting port :::1813
> Wed Aug 30 17:43:05 2017: DEBUG: Creating authentication port 0.0.0.0:1645
> Wed Aug 30 17:43:05 2017: ERR: Could not bind authentication socket: Address already in use
> Wed Aug 30 17:43:05 2017: DEBUG: Creating authentication port 0.0.0.0:1812
> Wed Aug 30 17:43:05 2017: ERR: Could not bind authentication socket: Address already in use
> Wed Aug 30 17:43:05 2017: DEBUG: Creating accounting port 0.0.0.0:1646
> Wed Aug 30 17:43:05 2017: ERR: Could not bind accounting socket: Address already in use
> Wed Aug 30 17:43:05 2017: DEBUG: Creating accounting port 0.0.0.0:1813
> Wed Aug 30 17:43:05 2017: ERR: Could not bind accounting socket: Address already in use
> Wed Aug 30 17:43:05 2017: NOTICE: Server started: Radiator 4.19 on radiator (LOCKED)
> Wed Aug 30 17:45:17 2017: DEBUG: Packet dump:
> *** Received from 172.16.0.240 port 33013 ....
> Code: Access-Request
> Identifier: 225
> Authentic: <232><231><153>a<180><219><251><197><254><197><155><254><233><213><5>h
> Attributes:
> User-Name = "vodar"
> CHAP-Password = <19><12>|<193><138><198>3<203>;LZ ><130><220>Q<215>
> NAS-Identifier = "F8-E7-1E-07-1D-20"
> NAS-IP-Address = 172.16.0.189
> Framed-IP-Address = 172.16.0.198
> Called-Station-Id = "f8-e7-1e-07-1d-20:ruckus-web-auth"
> Service-Type = Login-User
> Calling-Station-Id = "b4-6d-83-76-f2-91"
> NAS-Port-Type = Wireless-IEEE-802-11
> Ruckus-SSID = "ruckus-web-auth"
> Ruckus-Zone-Name = "kccg-office"
> Ruckus-Wlan-Name = "ruckus-web-auth"
> Ruckus-BSSID = <248><231><30><7><29>,
> Message-Authenticator = k$H<225><251><146>V<178><27>O<195><144>MO<6>t
> CHAP-Challenge = <133>r<13><132><150><170><234>7<30><202>IC<203><19><179><143>
> Chargeable-User-Identity = <0>
> Proxy-State = 101
>
> Wed Aug 30 17:45:17 2017: DEBUG: Handling request with Handler 'Realm=', Identifier ''
> Wed Aug 30 17:45:17 2017: DEBUG: OnlineUsers Deleting session for vodar, 172.16.0.189, 0
> Wed Aug 30 17:45:17 2017: DEBUG: Connecting to 'dbi:mysql:radmin:localhost Connection id: 0-00000'
>
> Wed Aug 30 17:45:18 2017: DEBUG: do query to 'dbi:mysql:radmin:localhost Connection id: 0-00000': 'delete from RADONLINE where NASIDENTIFIER='172.16.0.189' and NASPORT=00':
> Wed Aug 30 17:45:18 2017: DEBUG: Query to 'dbi:mysql:radmin:localhost Connection id: 0-00000': 'select NASIDENTIFIER, NASPORT, ACCTSESSIONID, FRAMEDIPADDRESS from RADONLINE where USERNAME='vodar'':
> Wed Aug 30 17:45:18 2017: DEBUG: Handling with Radius::AuthSQL: SQL-acct
> Wed Aug 30 17:45:18 2017: DEBUG: Handling with Radius::AuthSQL: SQL-acct
> Wed Aug 30 17:45:18 2017: DEBUG: Query to 'dbi:mysql:radmin:localhost Connection id: 0-00000': 'select PASSWORD from SUBSCRIBERS where USERNAME='vodar'':
> Wed Aug 30 17:45:18 2017: ERR: Execute failed for 'select PASSWORD from SUBSCRIBERS where USERNAME='vodar'': Table 'radmin.SUBSCRIBERS' doesn't exist
> Wed Aug 30 17:45:18 2017: DEBUG: Connecting to 'dbi:mysql:radmin:localhost Connection id: 0-00000'
>
> Wed Aug 30 17:45:18 2017: DEBUG: Query to 'dbi:mysql:radmin:localhost Connection id: 0-00000': 'select PASSWORD from SUBSCRIBERS where USERNAME='vodar'':
> Wed Aug 30 17:45:18 2017: ERR: Execute failed for 'select PASSWORD from SUBSCRIBERS where USERNAME='vodar'': Table 'radmin.SUBSCRIBERS' doesn't exist
> Wed Aug 30 17:45:18 2017: DEBUG: Radius::AuthSQL looks for match with vodar [vodar]
> Wed Aug 30 17:45:18 2017: DEBUG: Radius::AuthSQL REJECT: No such user: vodar [vodar]
> Wed Aug 30 17:45:18 2017: DEBUG: Connecting to 'dbi:mysql:radmin:localhost Connection id: 0-00000'
>
> Wed Aug 30 17:45:18 2017: DEBUG: Query to 'dbi:mysql:radmin:localhost Connection id: 0-00000': 'select PASSWORD from SUBSCRIBERS where USERNAME='DEFAULT'':
> Wed Aug 30 17:45:18 2017: ERR: Execute failed for 'select PASSWORD from SUBSCRIBERS where USERNAME='DEFAULT'': Table 'radmin.SUBSCRIBERS' doesn't exist
> Wed Aug 30 17:45:18 2017: DEBUG: Connecting to 'dbi:mysql:radmin:localhost Connection id: 0-00000'
>
> Wed Aug 30 17:45:18 2017: DEBUG: Query to 'dbi:mysql:radmin:localhost Connection id: 0-00000': 'select PASSWORD from SUBSCRIBERS where USERNAME='DEFAULT'':
> Wed Aug 30 17:45:18 2017: ERR: Execute failed for 'select PASSWORD from SUBSCRIBERS where USERNAME='DEFAULT'': Table 'radmin.SUBSCRIBERS' doesn't exist
> Wed Aug 30 17:45:18 2017: DEBUG: AuthBy SQL result: REJECT, No such user
> Wed Aug 30 17:45:18 2017: DEBUG: Handling with Radius::AuthSQL: SQL-auth
> Wed Aug 30 17:45:18 2017: DEBUG: Handling with Radius::AuthSQL: SQL-auth
> Wed Aug 30 17:45:18 2017: DEBUG: Connecting to 'dbi:mysql:radmin:localhost Connection id: 0-00000'
>
> Wed Aug 30 17:45:18 2017: DEBUG: Query to 'dbi:mysql:radmin:localhost Connection id: 0-00000': 'select PASS_WORD, OCTETSOUTLEFT from RADUSERS where USERNAME='vodar' and OCTETSOUTLEFT > 0':
> Wed Aug 30 17:45:18 2017: DEBUG: Radius::AuthSQL looks for match with vodar [vodar]
> Wed Aug 30 17:45:18 2017: DEBUG: Radius::AuthSQL ACCEPT: : vodar [vodar]
> Wed Aug 30 17:45:18 2017: DEBUG: AuthBy SQL result: ACCEPT,
> Wed Aug 30 17:45:18 2017: DEBUG: Access accepted for vodar
> Wed Aug 30 17:45:18 2017: ERR: There is no value named Framed for attribute Service-Type. Using 0.
> Wed Aug 30 17:45:18 2017: DEBUG: Packet dump:
> *** Sending to 172.16.0.240 port 33013 ....
> Code: Access-Accept
> Identifier: 225
> Authentic: <222>.<8><9>Q<236><151><219><139>A<18>E<241><179><230>G
> Attributes:
> Service-Type = Framed
> Framed-Protocol = PPP
> Proxy-State = 101
> Message-Authenticator = <0><0><0><0><0><0><0><0><0><0><0><0><0><0><0><0>
>
> Wed Aug 30 17:45:18 2017: DEBUG: Packet dump:
> *** Received from 172.16.0.189 port 44955 ....
> Code: Accounting-Request
> Identifier: 229
> Authentic: 3<232><200><207><26>s<224>l<223>|i<155>.<161><7><129>
> Attributes:
> Acct-Session-Id = "59A6CF57-071D2000"
> Framed-IP-Address = 172.16.0.198
> Acct-Multi-Session-Id = "f8e71e071d2cb46d8376f29159a6cf570056"
> Acct-Link-Count = 1
> Acct-Status-Type = Start
> Acct-Authentic = RADIUS
> User-Name = "vodar"
> NAS-IP-Address = 172.16.0.189
> NAS-Identifier = "F8-E7-1E-07-1D-20"
> NAS-Port = 1
> Called-Station-Id = "F8-E7-1E-07-1D-20:ruckus-web-auth"
> Calling-Station-Id = "B4-6D-83-76-F2-91"
> NAS-Port-Type = Wireless-IEEE-802-11
> Connect-Info = "CONNECT 802.11a/n/ac"
> Event-Timestamp = 1504104290
> Ruckus-SSID = "ruckus-web-auth"
> Ruckus-BSSID = <248><231><30><7><29>,
> Ruckus-Wlan-Id = 1
> Ruckus-Sta-Vlan-Id = 1
> Ruckus-SCG-CBlade-IP = 2886729968
>
> Wed Aug 30 17:45:18 2017: DEBUG: Handling request with Handler 'Realm=', Identifier ''
> Wed Aug 30 17:45:18 2017: DEBUG: OnlineUsers Adding session for vodar, 172.16.0.189, 1
> Wed Aug 30 17:45:18 2017: DEBUG: OnlineUsers Deleting session for vodar, 172.16.0.189, 1
> Wed Aug 30 17:45:18 2017: DEBUG: do query to 'dbi:mysql:radmin:localhost Connection id: 0-00000': 'delete from RADONLINE where NASIDENTIFIER='172.16.0.189' and NASPORT=01':
> Wed Aug 30 17:45:18 2017: DEBUG: do query to 'dbi:mysql:radmin:localhost Connection id: 0-00000': 'insert into RADONLINE (USERNAME, NASIDENTIFIER, NASPORT, ACCTSESSIONID, TIME_STAMP, FRAMEDIPADDRESS, SERVICETYPE, CALLINGSTATIONID) values ('vodar', '172.16.0.189', 1, '59A6CF57-071D2000', 1504104318, '172.16.0.198', '', 'B4-6D-83-76-F2-91')':
> Wed Aug 30 17:45:18 2017: DEBUG: Handling with Radius::AuthSQL: SQL-acct
> Wed Aug 30 17:45:18 2017: DEBUG: Handling accounting with Radius::AuthSQL
> Wed Aug 30 17:45:18 2017: DEBUG: do query to 'dbi:mysql:radmin:localhost Connection id: 0-00000': 'update RADUSERS set TIMELEFT=TIMELEFT-0, OCTETSINLEFT=OCTETSINLEFT-0, OCTETSOUTLEFT=OCTETSOUTLEFT-0 where USERNAME='vodar'':
> Wed Aug 30 17:45:18 2017: DEBUG: do query to 'dbi:mysql:radmin:localhost Connection id: 0-00000': 'insert into RADUSAGE (ACCTSESSIONID,ACCTSTATUSTYPE,CALLINGSTATIONID,DNIS,FRAMEDIPADDRESS,NASIDENTIFIER,NASPORT,TIME_STAMP,USERNAME) values ('59A6CF57-071D2000',1,'B4-6D-83-76-F2-91','F8-E7-1E-07-1D-20:ruckus-web-auth','172.16.0.198','F8-E7-1E-07-1D-20',1,1504104318,'vodar')':
> Wed Aug 30 17:45:18 2017: DEBUG: AuthBy SQL result: ACCEPT,
> Wed Aug 30 17:45:18 2017: DEBUG: Accounting accepted
> Wed Aug 30 17:45:18 2017: DEBUG: Packet dump:
> *** Sending to 172.16.0.189 port 44955 ....
> Code: Accounting-Response
> Identifier: 229
> Authentic: <27><183>&<136><<251><215>M<160>GX<200>5K<135>V
> Attributes:
>
> Wed Aug 30 17:46:18 2017: DEBUG: Packet dump:
> *** Received from 172.16.0.189 port 44955 ....
> Code: Accounting-Request
> Identifier: 230
> Authentic: 7<250><168>R<215><129><<23><200><139>3R<169>2T<168>
> Attributes:
> Acct-Session-Id = "59A6CF57-071D2000"
> Framed-IP-Address = 172.16.0.198
> Acct-Multi-Session-Id = "f8e71e071d2cb46d8376f29159a6cf570056"
> Acct-Link-Count = 1
> Acct-Status-Type = Alive
> Acct-Authentic = RADIUS
> User-Name = "vodar"
> NAS-IP-Address = 172.16.0.189
> NAS-Identifier = "F8-E7-1E-07-1D-20"
> NAS-Port = 1
> Called-Station-Id = "F8-E7-1E-07-1D-20:ruckus-web-auth"
> Calling-Station-Id = "B4-6D-83-76-F2-91"
> NAS-Port-Type = Wireless-IEEE-802-11
> Connect-Info = "CONNECT 802.11a/n/ac"
> Event-Timestamp = 1504104350
> Ruckus-SSID = "ruckus-web-auth"
> Ruckus-BSSID = <248><231><30><7><29>,
> Ruckus-Wlan-Id = 1
> Ruckus-Sta-Vlan-Id = 1
> Ruckus-SCG-CBlade-IP = 2886729968
> Acct-Input-Packets = 2693
> Acct-Output-Packets = 2690
> Acct-Input-Octets = 610449
> Acct-Output-Octets = 1961758
> Ruckus-Sta-RSSI = 52
> Acct-Session-Time = 60
>
> Wed Aug 30 17:46:18 2017: DEBUG: Handling request with Handler 'Realm=', Identifier ''
> Wed Aug 30 17:46:18 2017: DEBUG: OnlineUsers Adding session for vodar, 172.16.0.189, 1
> Wed Aug 30 17:46:18 2017: DEBUG: OnlineUsers Deleting session for vodar, 172.16.0.189, 1
> Wed Aug 30 17:46:18 2017: DEBUG: do query to 'dbi:mysql:radmin:localhost Connection id: 0-00000': 'delete from RADONLINE where NASIDENTIFIER='172.16.0.189' and NASPORT=01':
> Wed Aug 30 17:46:18 2017: DEBUG: do query to 'dbi:mysql:radmin:localhost Connection id: 0-00000': 'insert into RADONLINE (USERNAME, NASIDENTIFIER, NASPORT, ACCTSESSIONID, TIME_STAMP, FRAMEDIPADDRESS, SERVICETYPE, CALLINGSTATIONID) values ('vodar', '172.16.0.189', 1, '59A6CF57-071D2000', 1504104378, '172.16.0.198', '', 'B4-6D-83-76-F2-91')':
> Wed Aug 30 17:46:18 2017: DEBUG: Handling with Radius::AuthSQL: SQL-acct
> Wed Aug 30 17:46:18 2017: DEBUG: Handling accounting with Radius::AuthSQL
> Wed Aug 30 17:46:18 2017: DEBUG: do query to 'dbi:mysql:radmin:localhost Connection id: 0-00000': 'update RADUSERS set TIMELEFT=TIMELEFT-060, OCTETSINLEFT=OCTETSINLEFT-0610449, OCTETSOUTLEFT=OCTETSOUTLEFT-01961758 where USERNAME='vodar'':
> Wed Aug 30 17:46:18 2017: DEBUG: do query to 'dbi:mysql:radmin:localhost Connection id: 0-00000': 'insert into RADUSAGE (ACCTINPUTOCTETS,ACCTOUTPUTOCTETS,ACCTSESSIONID,ACCTSESSIONTIME,ACCTSTATUSTYPE,CALLINGSTATIONID,DNIS,FRAMEDIPADDRESS,NASIDENTIFIER,NASPORT,TIME_STAMP,USERNAME) values (610449,1961758,'59A6CF57-071D2000',60,3,'B4-6D-83-76-F2-91','F8-E7-1E-07-1D-20:ruckus-web-auth','172.16.0.198','F8-E7-1E-07-1D-20',1,1504104378,'vodar')':
> Wed Aug 30 17:46:18 2017: DEBUG: AuthBy SQL result: ACCEPT,
> Wed Aug 30 17:46:18 2017: DEBUG: Accounting accepted
> Wed Aug 30 17:46:18 2017: DEBUG: Packet dump:
> *** Sending to 172.16.0.189 port 44955 ....
> Code: Accounting-Response
> Identifier: 230
> Authentic: \<132><205><135><194><197><153><8>B<3>C<201>O<237><204><5>
> Attributes:
> .
> .
> .
> It keep logging the "alive" packet even the USERAME has exceed the OCTETSOUTLEFT. No Disconnect-Request called.
> ---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
>
> Any advice is appreciated. Thank you.
>
>
> Best Regards,
>
> Mustofa Haykal
> System Engineer
> Kuwaiti Canadian Consulting Group (www.kccg.com)
> T: +965 66576863
> F: +965 22415149
> E:mustofa at kccg.com
>
>
>
--
Hugh Irvine
hugh at open.com.au
Radiator: the most portable, flexible and configurable RADIUS server
anywhere. SQL, proxy, DBM, files, LDAP, NIS+, password, NT, Emerald,
Platypus, Freeside, TACACS+, PAM, external, Active Directory, EAP, TLS,
TTLS, PEAP, TNC, WiMAX, RSA, Vasco, Yubikey, MOTP, HOTP, TOTP,
DIAMETER, SIM, etc.
Full source on Unix, Linux, Windows, MacOSX, Solaris, VMS, NetWare etc.
More information about the radiator
mailing list