(RADIATOR) get_attr occasionally incorrectly returning NULL
Hugh Irvine
hugh at open.com.au
Fri May 6 05:52:17 CDT 2005
Hello Andrew -
I can't see anything wrong either.
Suggest you add some debugging code to your hook to log the
Acct-Session-Id value that the hook code is using.
regards
Hugh
On 6 May 2005, at 13:26, Andrew Sands wrote:
> Hi,
>
> I have a situation where I use get_attr in a postauthhook and in over
> 100000 requests last month it worked but on 24 occasions it returned
> NULL when I know it should never do that. I wonder if anyone else has
> ever experienced this, can see a mistake in what I am doing, or can
> suggest a fix?
>
> First of all I know that the Acct-Session-Id is not NULL for this STOP
> accounting record because I can see it in the trace as follows:
>
> Mon Apr 4 13:38:58 2005: DEBUG: Packet dump:
> *** Received from xx.xx.xx.xx port 1813 ....
> Code: Accounting-Request
> Identifier: 230
> Authentic: ".<137><143><166>#<11><249>f<<221>`<208><255><198>5
> Attributes:
> Acct-Session-Id = "000C0BB2"
> Framed-Protocol = PPP
> Acct-Authentic = RADIUS
> Ascend-Disconnect-Cause = 816
> Ascend-Connect-Progress = prLanSessionUp
> Ascend-PreSession-Time = 29
> Ascend-Xmit-Rate = 50667
> Ascend-Data-Rate = 28800
> Acct-Session-Time = 578
> Acct-Input-Octets = 302699
> Acct-Output-Octets = 1626030
> Ascend-Pre-Input-Octets = 336
> Ascend-Pre-Output-Octets = 113
> Acct-Input-Packets = 2508
> Acct-Output-Packets = 1479
> Ascend-Pre-Input-Packets = 8
> Ascend-Pre-Output-Packets = 4
> Acct-Status-Type = Stop
> Acct-Multi-Session-Id = "00078981"
> Ascend-Multilink-ID = 493953
> Acct-Link-Count = 1
> Ascend-Num-In-Multilink = 1
> Framed-IP-Address = xx.xx.162.191
> Called-Station-Id = "142330755113178"
> NAS-Port-Type = Async
> NAS-Port = 6374
> Service-Type = Framed-User
> NAS-IP-Address = xx.xx.238.101
> Ascend-Session-Svr-Key = "7FF3E294"
> NAS-Identifier = "xxx-JOHN-STP.xxxxx.com.au"
> Acct-Delay-Time = 10
> User-Name = "xxx_wl/xxxx at xxxx.com.au"
> Proxy-State =
> BSP2MyMaster/
> 65CD748FC992421A4DC536282071BB582ED040F5D715D29899B43997D804E52D6C80F93
> FD715D0125268D65EDE6AFDC9A75D5AEAD71DF107A1D7505AAA6FCEB20BF291368862BC
> 28F8C1505AB6448EA015EE9D21B079BF65F8D81658B769D3AA19
>
> I can also see from the TRACE debug that there were no errors
> experienced during the processing:
>
> Mon Apr 4 13:38:58 2005: DEBUG: Handling request with Handler
> 'User-Name = /^our_partner\//i'
> Mon Apr 4 13:38:58 2005: DEBUG: Rewrote user name to xxxx at xxxx.com.au
> Mon Apr 4 13:38:58 2005: DEBUG: SDB1 Deleting session for
> xxx_wl/xxxx at xxxx.com.au, xx.xx.238.101, 6374
> Mon Apr 4 13:38:58 2005: DEBUG: do query is: 'delete from RADONLINE
> where NASIDENTIFIER='xx.xx.238.101' and NASPORT='6374'':
> Mon Apr 4 13:38:58 2005: DEBUG: PostAuthHook network-access
> ++++++++++++++++++++++++++++
> Mon Apr 4 13:38:58 2005: DEBUG: execute SQL okay
> Mon Apr 4 13:38:58 2005: DEBUG: PostAuthHook network-access
> ----------------------------
> Mon Apr 4 13:38:58 2005: DEBUG: Accounting accepted
>
>
> When I look in the database at the saved STOP record I can see:
>
> mysql> select * from RADUSAGE_200504 where ACCTSESSIONID = 'NULL' and
> ACCTSTATUSTYPE = 2 and USERNAME like 'xxxx%'\G;
> *************************** 1. row ***************************
> ACCTDELAYTIME: 10
> ACCTINPUTOCTETS: 302699
> ACCTOUTPUTOCTETS: 1626030
> ACCTSESSIONID: NULL
> ACCTSESSIONTIME: 578
> ACCTSTATUSTYPE: 2
> ACCTTERMINATECAUSE: NULL
> FRAMEDIPADDRESS: xx.xx.162.191
> NASIDENTIFIER: NULL
> NASPORT: 6374
> NAS_PORT_TYPE: NULL
> TIME_STAMP: 1112585928
> USERNAME: xxxx at xxxx.com.au
> 1 row in set (0.01 sec)
>
>
> The missing ACCTSESSIONID was not used anywhere else:
>
> mysql> select count(*) from RADUSAGE_200504 where ACCTSESSIONID =
> '000C0BB2';
> +----------+
> | count(*) |
> +----------+
> | 0 |
> +----------+
> 1 row in set (1.28 sec)
>
>
> This has happened only 24 times during the month:
>
> mysql> select count(*) from RADUSAGE_200504 where ACCTSESSIONID =
> 'NULL';
> +----------+
> | count(*) |
> +----------+
> | 24 |
> +----------+
> 1 row in set (1.01 sec)
>
>
>
> The ACCTSESSIONID is being set to the string ‘NULL’ rather than being
> set to a NULL:
> (a minor problem I’m ignoring at the moment).
>
> mysql> select count(*) from RADUSAGE_200504 where ACCTSESSIONID is
> NULL and ACCTSTATUSTYPE = 2;
> +----------+
> | count(*) |
> +----------+
> | 0 |
> +----------+
> 1 row in set (0.99 sec)
>
>
> mysql> select count(*) from RADUSAGE_200504;
> +----------+
> | count(*) |
> +----------+
> | 132248 |
> +----------+
> 1 row in set (0.00 sec)
>
> mysql>
>
>
>
>
> The relevant Radius Config is:
>
>
> <Handler User-Name = /^our_partner\//i >
> RewriteUsername s/^our_partner\/(.*)/$1/
> AuthByPolicy ContinueAlways
> AuthBy CheckRadmin
> AuthLog ALDB1
> SessionDatabase SDB1
> PostAuthHook file:"%D/network_access.pl"
> </Handler>
>
>
> And the relevant bits of the postauthhook are:
>
> sub
> {
> my $p = ${$_[0]};
> my $rp = ${$_[1]};
> my $result = ${$_[2]};
>
> &main::log($main::LOG_DEBUG,"PostAuthHook network-access
> ++++++++++++++++++++++++++++");
>
> my $u_name = $p->get_attr('User-Name');
>
> my $a_TIME_STAMP ;
> my $a_ACCTSTATUSTYPE ;
> my $a_ACCTDELAYTIME ;
> my $a_ACCTINPUTOCTETS ;
> my $a_ACCTOUTPUTOCTETS ;
> my $a_ACCTSESSIONID ;
> my $a_ACCTSESSIONTIME ;
> my $a_ACCTTERMINATECAUSE ;
> my $a_NASIDENTIFIER ;
> my $a_NASPORT ;
> my $a_NAS_PORT_TYPE ;
> my $a_FRAMEDIPADDRESS ;
>
> my $req_type = "?";
>
> $req_type = $p->code;
>
> if ($req_type eq 'Access-Request') {
> # Other stuff
> } else {
> $a_TIME_STAMP = $p-> get_attr('Timestamp');
> $a_ACCTSTATUSTYPE = $p->
> get_attr('Acct-Status-Type');
> $a_ACCTSTATUSTYPE =
> $rp->{Dict}->valNameToNum('Acct-Status-Type', $a_ACCTSTATUSTYPE);
> $a_ACCTDELAYTIME = $p->
> get_attr('Acct-Delay-Time');
>
> if ($a_ACCTDELAYTIME eq "") {
> $a_ACCTDELAYTIME = "NULL";
> }
>
> $a_ACCTINPUTOCTETS = $p->
> get_attr('Acct-Input-Octets');
> if ($a_ACCTINPUTOCTETS eq "") {
> $a_ACCTINPUTOCTETS = "NULL";
> }
>
> $a_ACCTOUTPUTOCTETS = $p->
> get_attr('Acct-Output-Octets');
> if ($a_ACCTOUTPUTOCTETS eq "") {
> $a_ACCTOUTPUTOCTETS = "NULL";
> }
>
> $a_ACCTSESSIONID = $p->
> get_attr('Acct-Session-Id');
>
>
> # Other attributes gathered, and connect to database …
>
> my $insert_sql;
> my $insert_text;
>
> $insert_text = "INSERT INTO RADUSAGE_200504
> (ACCTDELAYTIME,ACCTINPUTOCTETS,ACCTOUTPUTOCTETS,ACCTSESSIONID,ACCTSESSI
> ONTIME,ACCTSTATUSTYPE,ACCTTERMINATECAUSE,FRAMEDIPADDRESS,NASIDENTIFIER,
> NASPORT,NAS_PORT_TYPE,TIME_STAMP,USERNAME) VALUES
> ($a_ACCTDELAYTIME,$a_ACCTINPUTOCTETS,$a_ACCTOUTPUTOCTETS,'$a_ACCTSESSIO
> NID',$a_ACCTSESSIONTIME,$a_ACCTSTATUSTYPE,'$a_ACCTTERMINATECAUSE','$a_F
> RAMEDIPADDRESS','$a_NASIDENTIFIER',$a_NASPORT,$a_NAS_PORT_TYPE,$a_TIME_
> STAMP,'$u_name');";
> }
>
> ($insert_sql) = $dbh->prepare (qq{$insert_text});
> if ($insert_sql->execute()) {
> &main::log($main::LOG_DEBUG,"execute SQL
> okay");
> } else {
> # Other error handling code
> }
> }
>
> &main::log($main::LOG_DEBUG,"PostAuthHook network-access
> ----------------------------");
> return;
> }
>
>
>
NB:
Have you read the reference manual ("doc/ref.html")?
Have you searched the mailing list archive
(www.open.com.au/archives/radiator)?
Have you had a quick look on Google (www.google.com)?
Have you included a copy of your configuration file (no secrets),
together with a trace 4 debug showing what is happening?
--
Radiator: the most portable, flexible and configurable RADIUS server
anywhere. Available on *NIX, *BSD, Windows, MacOS X.
-
Nets: internetwork inventory and management - graphical, extensible,
flexible with hardware, software, platform and database independence.
-
CATool: Private Certificate Authority for Unix and Unix-like systems.
--
Archive at http://www.open.com.au/archives/radiator/
Announcements on radiator-announce at open.com.au
To unsubscribe, email 'majordomo at open.com.au' with
'unsubscribe radiator' in the body of the message.
More information about the radiator
mailing list