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 i...@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:must...@kccg.com


---- Original Message ----
From: "Hugh Irvine" <h...@open.com.au>
Sent: 9/6/2017 2:03:19 AM
To: "Mustofa Haykal" <must...@kccg.com>
Cc: "radiator" <radiator@lists.open.com.au>, "adam" <a...@kccg.com>, "thomas" 
<tho...@kccg.com>, h...@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 <must...@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 i...@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:must...@kccg.com
> 
> 
> 


--

Hugh Irvine
h...@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.



_______________________________________________
radiator mailing list
radiator@lists.open.com.au
http://lists.open.com.au/mailman/listinfo/radiator

Reply via email to