[RADIATOR] Fail to Call radpwtst From Hook File
Hugh Irvine
hugh at open.com.au
Thu Sep 7 04:14:00 UTC 2017
Hello Mustofa -
You also have a problem in your configuration file, with a mix of <Realm> and <Handler …> clauses.
As you can see in the debug log, the <Realm> clause is always being called, which is the default behaviour.
Because the <Realm> clause is always called, the <Handler …> clauses are never called.
This is why you should never mix <Realm> and <Handler ….> clauses.
You should do something like this instead:
# define AuthBy clauses with Identifiers
<AuthBy SQL>
Identifier SQL-auth
…..
</AuthBy>
<AuthBy SQL>
Identifier SQL-acct
…..
</AuthBy>
# define Handlers
<Handler Acct-Status-Type = Alive>
# process Alives
…..
</Handler>
<Handler Request-Type = Accounting-Request>
# process other accounting
…..
</Handler>
<Handler>
# process authentication and any other requests
…..
</Handler>
hope that helps
regards
Hugh
> On 6 Sep 2017, at 19:41, Mustofa Haykal <mustofa at kccg.com> wrote:
>
> 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.
>
>
>
--
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