[RADIATOR] Errors on database
Carlos Parada
carlos-f-parada at ptinovacao.pt
Thu Apr 1 05:22:56 CDT 2010
Hi again,
Still regarding to this problem, I have been testing and I found out what is causing this behavior (or at least, what is related to it).
I have <AddressAllocator SQL>/<AuthBy DYNADDRESS> configurations for IP allocation purposes.
And, I found out that removing this configuration and, therefore, the queries that those modules do to the database (at startup to create one row per address), Radiator never fails (in both scenarios; either when the radpool table is already populated or when it is empty and the rows have to be inserted). However, the very next query (on receiving RADIUS traffic) always fails. Furthermore, I found out that removing the IP allocation from my configuration files (and therefore not executing these initial queries), this problem never occurs.
So, it seems that the queries that follow the IP allocation at startup, are somehow trying to use this startup connection, and it is already corrupted. I've tested using forking servers (farmsize) and not using, and the problem is the same.
So, I believe that this could be a "bug" in the way Radiator tries to use a wrong connection handler to the database. Maybe you can replicate the problem there.
Am I right? Make this any sense for you or helps on solving the problem?
Regards,
Calos Parada
-----Original Message-----
From: radiator-bounces at open.com.au [mailto:radiator-bounces at open.com.au] On Behalf Of Carlos Parada
Sent: quinta-feira, 1 de Abril de 2010 09:34
To: Hugh Irvine
Cc: radiator at open.com.au
Subject: Re: [RADIATOR] Errors on database
Hugh,
In this example the error occurs in the DELETE, but just because this is the first statement to execute. I have other examples where is the SELECT the first execution and is there where the error occurs.
Regards,
Carlos Parada
-----Original Message-----
From: Hugh Irvine [mailto:hugh at open.com.au]
Sent: quarta-feira, 31 de Março de 2010 22:53
To: Carlos Parada
Cc: radiator at open.com.au; Carlos Rodrigues
Subject: Re: [RADIATOR] Errors on database
Hello Carlos -
Thanks for the additional information.
It appears that the error occurs on the first delete, rather than the first access, as the address pool appears to be read correctly?
I think you will need to check the DBI/DBD-Pg modules to see if there is a version problem.
Otherwise you may be able to use a ConnectionHook in the AuthBy SQL clause to set up the connection.
See section 5.29.24 in the Radiator 4.6 reference manual ("doc/ref.pdf").
There are many example hooks in "goodies/hooks.txt".
regards
Hugh
On 31 Mar 2010, at 22:20, Carlos Parada wrote:
> Hi Hugh,
>
> Here I send you part of the configs and logs (the key parts).
> The problem occurs anytime on the first database access (postgres), no mather what configurations I have. Here I send you an example, but I could find many others.
>
> If needed, I can send you a most complete information (configs and logs). However,
> it would be more confusing because it includes code made by ourselves. I would like
> to left clear that this errors occurs in a clean Radiator version (this logs is for a
> clean Radiator).
>
>
> Regards,
> Carlos Parada
>
> ### SQL Auth (WiFi)
> <AuthBy FREERADIUSSQL>
> Identifier local_db_wifi
> DBSource dbi:Pg:dbname=aaa;host=10.112.25.65;port=5432
> DBUsername aaa
> DBAuth aaa
>
> # Not finished!!!
> #Timeout 1
> #FailureBackoffTime 5
>
> # Handling Accounting
> AuthSelectParam %u
> AuthSelectParam %u
> AuthSelectParam %u
> AuthSelectParam %u
> AuthCheck SELECT id, UserName, Attribute, Value, op FROM radcheck WHERE Username=? ORDER BY id
> AuthReply SELECT id, UserName, Attribute, Value, op FROM radreply WHERE Username=? ORDER BY id
> AuthGroupCheck SELECT radgroupcheck.id,radgroupcheck.GroupName,radgroupcheck.Attribute,\
> radgroupcheck.Value,radgroupcheck.op FROM radgroupcheck,usergroup WHERE \
> usergroup.Username = ? AND usergroup.GroupName = radgroupcheck.GroupName ORDER BY radgroupcheck.id
> AuthGroupReply SELECT radgroupcheck.id,radgroupcheck.GroupName,radgroupcheck.Attribute,\
> radgroupcheck.Value,radgroupcheck.op FROM radgroupcheck,usergroup WHERE usergroup.Username = ? \
> AND usergroup.GroupName = radgroupcheck.GroupName ORDER BY radgroupcheck.id
>
> # Handling Accounting
> AcctOnoffQuery UPDATE radacct SET AcctStopTime='%J', AcctSessionTime=unix_timestamp('%J') - \
> unix_timestamp(AcctStartTime), AcctTerminateCause='%{Acct-Terminate-Cause}', AcctStopDelay = '%{Acct-Delay-Time}' \
> WHERE AcctSessionTime=0 AND AcctStopTime=0 AND NASIPAddress= '%{NAS-IP-Address}' AND AcctStartTime <= '%J'
> AcctStartQuery INSERT into radacct (AcctSessionId, AcctUniqueId, UserName, Realm, NASIPAddress, NASPortId, \
> NASPortType, AcctStartTime, AcctStopTime, AcctSessionTime, AcctAuthentic, ConnectInfo_start, ConnectInfo_stop, \
> AcctInputOctets, AcctOutputOctets, CalledStationId, CallingStationId, AcctTerminateCause, ServiceType, FramedProtocol, \
> FramedIPAddress, AcctStartDelay, AcctStopDelay) values('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}', \
> '%{SQL-User-Name}', '%{Realm}', '%{NAS-IP-Address}', '%{NAS-Port}', '%{NAS-Port-Type}', '%J', NULL, '0', \
> '%{Acct-Authentic}', '%{Connect-Info}', '', '0', '0', '%{Called-Station-Id}', '%{Calling-Station-Id}', '', \
> '%{Service-Type}', '%{Framed-Protocol}', '%{Framed-IP-Address}', '%{Acct-Delay-Time}', '0')
> AcctStartQueryAlt UPDATE radacct SET AcctStartTime = '%J', AcctStartDelay = '%{Acct-Delay-Time}',\
> ConnectInfo_start = '%{Connect-Info}' WHERE AcctSessionId = '%{Acct-Session-Id}' AND UserName = '%{SQL-User-Name}' \
> AND NASIPAddress = '%{NAS-IP-Address}'
> AcctUpdateQuery UPDATE radacct SET \
> FramedIPAddress = '%{Framed-IP-Address}', \
> AcctSessionTime = '%{Acct-Session-Time}', \
> AcctInputOctets = '%{Acct-Input-Octets}', \
> AcctOutputOctets = '%{Acct-Output-Octets}' \
> WHERE AcctSessionId = '%{Acct-Session-Id}' \
> AND UserName = '%{SQL-User-Name}' \
> AND NASIPAddress= '%{NAS-IP-Address}'
> AcctUpdateQueryAlt INSERT into radacct (AcctSessionId, AcctUniqueId, UserName, Realm, NASIPAddress, \
> NASPortId, NASPortType, AcctStartTime, AcctSessionTime, AcctAuthentic, ConnectInfo_start, AcctInputOctets, \
> AcctOutputOctets, CalledStationId, CallingStationId, ServiceType, FramedProtocol, FramedIPAddress, AcctStartDelay) \
> values('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}', '%{SQL-User-Name}', '%{Realm}', '%{NAS-IP-Address}', \
> '%{NAS-Port}', '%{NAS-Port-Type}', DATE_SUB('%J',INTERVAL (%{Acct-Session-Time:-0} + %{Acct-Delay-Time:-0}) SECOND), \
> '%{Acct-Session-Time}', '%{Acct-Authentic}', '', '%{Acct-Input-Octets}', '%{Acct-Output-Octets}', '%{Called-Station-Id}', \
> '%{Calling-Station-Id}', '%{Service-Type}', '%{Framed-Protocol}', '%{Framed-IP-Address}', '0')
> AcctStopQuery UPDATE radacct SET AcctStopTime = '%J', AcctSessionTime = '%{Acct-Session-Time}', \
> AcctInputOctets = '%{Acct-Input-Octets}', AcctOutputOctets = '%{Acct-Output-Octets}', \
> AcctTerminateCause = '%{Acct-Terminate-Cause}', AcctStopDelay = '%{Acct-Delay-Time}', ConnectInfo_stop = \
> '%{Connect-Info}' WHERE AcctSessionId = '%{Acct-Session-Id}' AND UserName = '%{SQL-User-Name}' AND \
> NASIPAddress = '%{NAS-IP-Address}'
> AcctStopQueryAlt INSERT into radacct (AcctSessionId, AcctUniqueId, UserName, Realm, NASIPAddress, \
> NASPortId, NASPortType, AcctStartTime, AcctStopTime, AcctSessionTime, AcctAuthentic, ConnectInfo_start, \
> ConnectInfo_stop, AcctInputOctets, AcctOutputOctets, CalledStationId, CallingStationId, AcctTerminateCause, \
> ServiceType, FramedProtocol, FramedIPAddress, AcctStartDelay, AcctStopDelay) values('%{Acct-Session-Id}', \
> '%{Acct-Unique-Session-Id}', '%{SQL-User-Name}', '%{Realm}', '%{NAS-IP-Address}', '%{NAS-Port}', \
> '%{NAS-Port-Type}', DATE_SUB('%J', INTERVAL (%{Acct-Session-Time:-0} + %{Acct-Delay-Time:-0}) SECOND), \
> '%J', '%{Acct-Session-Time}', '%{Acct-Authentic}', '', '%{Connect-Info}', '%{Acct-Input-Octets}', \
> '%{Acct-Output-Octets}', '%{Called-Station-Id}', '%{Calling-Station-Id}', '%{Acct-Terminate-Cause}', \
> '%{Service-Type}', '%{Framed-Protocol}', '%{Framed-IP-Address}', '0', '%{Acct-Delay-Time}')
>
> # Performance
> # Cache
> #CachePasswords
> # fork any request
> #Fork
>
> # Address pool
> AddToReply PoolHint=pool1
> </AuthBy>
>
> <Handler Client-Identifier=WiFi>
> Identifier Handler_WiFi
>
> # Licensing?
> #MaxSessions 1000
>
> # Contnue running AuthBy until acceptanceance
> AuthByPolicy ContinueWhileAccept
>
> # Auth
> RejectHasReason
> AuthBy local_db_wifi
>
> ### IP address allocation
> AuthBy ip_dhcp
>
> # Logs
> #Auth Logs
> <AuthLog FILE>
> Identifier acc_log
> Filename %L/radius_acc.log
> LogSuccess 1
> SuccessFormat year=%Y,month=%m,day=%d,hour=%H,minute=%M,second=%S,microseconds=%s,\
> clientIP=%c,client-name=%{Client:name},profile=%{Handler:name},%{NAS-IP-Address},%{User-Name}\012
> LogFailure 1
> FailureFormat year=%Y,month=%m,day=%d,hour=%H,minute=%M,second=%S,microseconds=%s,\
> clientIP=%c,client-name=%{Client:name},profile=%{Handler:name},%{NAS-IP-Address},%{User-Name}\012
> </AuthLog>
> #Acct Logs
> AcctLogFileFormat year=%Y,month=%m,day=%d,hour=%H,minute=%M,second=%S,microseconds=%s,\
> clientIP=%c,client-name=%{Client:name},profile=%{Handler:name},%{NAS-IP-Address},%{User-Name}\012
> AcctLogFileName %L/radius_acc.log
> </Handler>
>
> ----------------------
>
> Logs:
> Tue Feb 9 16:16:28 2010: NOTICE: SIGTERM received: stopping
> Tue Feb 9 16:24:42 2010: DEBUG: include /etc/radiator/clients.cfg
> Tue Feb 9 16:24:42 2010: DEBUG: include /etc/radiator/wap.cfg
> Tue Feb 9 16:24:42 2010: DEBUG: include /etc/radiator/wifi.cfg
> Tue Feb 9 16:24:42 2010: DEBUG: Checking address 192.1.1.1
> Tue Feb 9 16:24:42 2010: DEBUG: Query is: 'SELECT STATE FROM RADPOOL WHERE YIADDR='192.1.1.1' LIMIT 1':
> Tue Feb 9 16:24:42 2010: DEBUG: Checking address 192.1.1.2
> Tue Feb 9 16:24:42 2010: DEBUG: Query is: 'SELECT STATE FROM RADPOOL WHERE YIADDR='192.1.1.2' LIMIT 1':
> Tue Feb 9 16:24:42 2010: DEBUG: Checking address 192.1.1.3
> Tue Feb 9 16:24:42 2010: DEBUG: Query is: 'SELECT STATE FROM RADPOOL WHERE YIADDR='192.1.1.3' LIMIT 1':
> Tue Feb 9 16:24:42 2010: DEBUG: Checking address 192.1.1.4
> Tue Feb 9 16:24:42 2010: DEBUG: Query is: 'SELECT STATE FROM RADPOOL WHERE YIADDR='192.1.1.4' LIMIT 1':
> Tue Feb 9 16:24:42 2010: DEBUG: Checking address 192.1.1.5
> Tue Feb 9 16:24:42 2010: DEBUG: Query is: 'SELECT STATE FROM RADPOOL WHERE YIADDR='192.1.1.5' LIMIT 1':
> Tue Feb 9 16:24:42 2010: DEBUG: Checking address 192.1.1.6
> Tue Feb 9 16:24:42 2010: DEBUG: Query is: 'SELECT STATE FROM RADPOOL WHERE YIADDR='192.1.1.6' LIMIT 1':
> Tue Feb 9 16:24:42 2010: DEBUG: Checking address 192.1.1.7
> Tue Feb 9 16:24:42 2010: DEBUG: Query is: 'SELECT STATE FROM RADPOOL WHERE YIADDR='192.1.1.7' LIMIT 1':
> Tue Feb 9 16:24:42 2010: DEBUG: Checking address 192.1.1.8
> Tue Feb 9 16:24:42 2010: DEBUG: Query is: 'SELECT STATE FROM RADPOOL WHERE YIADDR='192.1.1.8' LIMIT 1':
> Tue Feb 9 16:24:42 2010: DEBUG: Checking address 192.1.1.9
> Tue Feb 9 16:24:42 2010: DEBUG: Query is: 'SELECT STATE FROM RADPOOL WHERE YIADDR='192.1.1.9' LIMIT 1':
> Tue Feb 9 16:24:42 2010: DEBUG: Checking address 192.1.1.10
> Tue Feb 9 16:24:42 2010: DEBUG: Query is: 'SELECT STATE FROM RADPOOL WHERE YIADDR='192.1.1.10' LIMIT 1':
> Tue Feb 9 16:24:42 2010: DEBUG: Checking address 192.1.2.0
> Tue Feb 9 16:24:42 2010: DEBUG: Query is: 'SELECT STATE FROM RADPOOL WHERE YIADDR='192.1.2.0' LIMIT 1':
> Tue Feb 9 16:24:42 2010: DEBUG: Checking address 192.1.2.1
> Tue Feb 9 16:24:42 2010: DEBUG: Query is: 'SELECT STATE FROM RADPOOL WHERE YIADDR='192.1.2.1' LIMIT 1':
> Tue Feb 9 16:24:42 2010: DEBUG: Checking address 192.1.2.2
> Tue Feb 9 16:24:42 2010: DEBUG: Query is: 'SELECT STATE FROM RADPOOL WHERE YIADDR='192.1.2.2' LIMIT 1':
> Tue Feb 9 16:24:42 2010: DEBUG: Checking address 192.1.2.3
> Tue Feb 9 16:24:42 2010: DEBUG: Query is: 'SELECT STATE FROM RADPOOL WHERE YIADDR='192.1.2.3' LIMIT 1':
> Tue Feb 9 16:24:42 2010: DEBUG: Checking address 192.1.2.4
> Tue Feb 9 16:24:42 2010: DEBUG: Query is: 'SELECT STATE FROM RADPOOL WHERE YIADDR='192.1.2.4' LIMIT 1':
> Tue Feb 9 16:24:42 2010: DEBUG: Checking address 192.1.2.5
> Tue Feb 9 16:24:42 2010: DEBUG: Query is: 'SELECT STATE FROM RADPOOL WHERE YIADDR='192.1.2.5' LIMIT 1':
> Tue Feb 9 16:24:42 2010: DEBUG: Checking address 192.1.2.6
> Tue Feb 9 16:24:42 2010: DEBUG: Query is: 'SELECT STATE FROM RADPOOL WHERE YIADDR='192.1.2.6' LIMIT 1':
> Tue Feb 9 16:24:42 2010: DEBUG: Checking address 192.1.2.7
> Tue Feb 9 16:24:42 2010: DEBUG: Query is: 'SELECT STATE FROM RADPOOL WHERE YIADDR='192.1.2.7' LIMIT 1':
> Tue Feb 9 16:24:42 2010: DEBUG: Checking address 192.1.2.8
> Tue Feb 9 16:24:42 2010: DEBUG: Query is: 'SELECT STATE FROM RADPOOL WHERE YIADDR='192.1.2.8' LIMIT 1':
> Tue Feb 9 16:24:42 2010: DEBUG: Checking address 192.1.2.9
> Tue Feb 9 16:24:42 2010: DEBUG: Query is: 'SELECT STATE FROM RADPOOL WHERE YIADDR='192.1.2.9' LIMIT 1':
> Tue Feb 9 16:24:42 2010: DEBUG: Checking address 192.1.2.10
> Tue Feb 9 16:24:42 2010: DEBUG: Query is: 'SELECT STATE FROM RADPOOL WHERE YIADDR='192.1.2.10' LIMIT 1':
> Tue Feb 9 16:24:42 2010: DEBUG: Checking address 192.1.2.11
> Tue Feb 9 16:24:42 2010: DEBUG: Query is: 'SELECT STATE FROM RADPOOL WHERE YIADDR='192.1.2.11' LIMIT 1':
> Tue Feb 9 16:24:42 2010: DEBUG: Checking address 192.1.2.12
> Tue Feb 9 16:24:42 2010: DEBUG: Query is: 'SELECT STATE FROM RADPOOL WHERE YIADDR='192.1.2.12' LIMIT 1':
> Tue Feb 9 16:24:42 2010: DEBUG: Checking address 192.1.2.13
> Tue Feb 9 16:24:42 2010: DEBUG: Query is: 'SELECT STATE FROM RADPOOL WHERE YIADDR='192.1.2.13' LIMIT 1':
> Tue Feb 9 16:24:42 2010: DEBUG: Checking address 192.1.2.14
> Tue Feb 9 16:24:42 2010: DEBUG: Query is: 'SELECT STATE FROM RADPOOL WHERE YIADDR='192.1.2.14' LIMIT 1':
> Tue Feb 9 16:24:42 2010: DEBUG: Checking address 192.1.2.15
> Tue Feb 9 16:24:42 2010: DEBUG: Query is: 'SELECT STATE FROM RADPOOL WHERE YIADDR='192.1.2.15' LIMIT 1':
> Tue Feb 9 16:24:42 2010: DEBUG: Reclaiming expired leases
> Tue Feb 9 16:24:42 2010: DEBUG: do query is: 'UPDATE RADPOOL SET STATE=0 WHERE STATE!=0 AND EXPIRY < 1265732682':
> Tue Feb 9 16:24:42 2010: DEBUG: include /etc/radiator/roaming.cfg
> Tue Feb 9 16:24:42 2010: DEBUG: include /etc/radiator/proxies.cfg
> Tue Feb 9 16:24:42 2010: DEBUG: Finished reading configuration file '/etc/radiator/radius.cfg'
> Tue Feb 9 16:24:42 2010: DEBUG: Reading dictionary file '/etc/radiator/dictionary'
> Tue Feb 9 16:24:42 2010: DEBUG: Creating authentication port 0.0.0.0:1812
> Tue Feb 9 16:24:42 2010: DEBUG: Creating accounting port 0.0.0.0:1813
> Tue Feb 9 16:24:42 2010: NOTICE: Server started: Radiator 4.4 on dscp2 (LOCKED)
> Tue Feb 9 16:36:04 2010: DEBUG: Packet dump:
> *** Received from 10.112.48.185 port 32882 ....
> Code: Access-Request
> Identifier: 64
> Authentic: <131><252>9<131><245>f<14><202>>R<237><175>F<160>5;
> Attributes:
> User-Name = "user at tmn.pt"
> Service-Type = Framed-User
> NAS-IP-Address = 203.63.154.1
> NAS-Identifier = "203.63.154.11"
> NAS-Port = 1234
> Called-Station-Id = "123456789"
> Calling-Station-Id = "987654321"
> NAS-Port-Type = Async
> User-Password = a<155>C<212><130>i~<224><214><212>S<191><151><155><215><255>
> Called-Station-Id = "12345"
> Framed-Protocol = PPP
>
> Tue Feb 9 16:36:04 2010: DEBUG: Handling request with Handler 'Client-Identifier=WiFi'
> Tue Feb 9 16:36:04 2010: DEBUG: WAP_TMN Deleting session for user at tmn.pt, 203.63.154.1, 1234
> Tue Feb 9 16:36:04 2010: DEBUG: do query is: 'DELETE FROM session WHERE NASIDENTIFIER='203.63.154.1' AND NASPORT=1234':
> Tue Feb 9 16:36:04 2010: ERR: do failed for 'DELETE FROM session WHERE NASIDENTIFIER='203.63.154.1' AND NASPORT=1234': server close
> d the connection unexpectedly
> This probably means the server terminated abnormally
> before or while processing the request.
> Tue Feb 9 16:36:04 2010: DEBUG: Handling with Radius::AuthFREERADIUSSQL: local_db_wifi
> Tue Feb 9 16:36:04 2010: DEBUG: Handling with Radius::AuthFREERADIUSSQL: local_db_wifi
> Tue Feb 9 16:36:04 2010: DEBUG: Query is: 'SELECT id, UserName, Attribute, Value, op FROM radcheck WHERE Username=? ORDER BY id': u
> ser at tmn.pt
> Tue Feb 9 16:36:04 2010: DEBUG: Got user check row: 3 user at tmn.pt Password pass =
> Tue Feb 9 16:36:04 2010: DEBUG: Query is: 'SELECT id, UserName, Attribute, Value, op FROM radreply WHERE Username=? ORDER BY id': u
> ser at tmn.pt
> Tue Feb 9 16:36:04 2010: DEBUG: Got user reply row: 3 user at tmn.pt Framed-IP-Address 255.255.255.254 =
> Tue Feb 9 16:36:04 2010: DEBUG: Query is: 'SELECT radgroupcheck.id,radgroupcheck.GroupName,radgroupcheck.Attribute,radgroupcheck.Va
> lue,radgroupcheck.op FROM radgroupcheck,usergroup WHERE usergroup.Username = ? AND usergroup.GroupName = radgroupcheck.GroupName ORD
> ER BY radgroupcheck.id': user at tmn.pt
> Tue Feb 9 16:36:04 2010: DEBUG: Query is: 'SELECT radgroupcheck.id,radgroupcheck.GroupName,radgroupcheck.Attribute,radgroupcheck.Va
> lue,radgroupcheck.op FROM radgroupcheck,usergroup WHERE usergroup.Username = ? AND usergroup.GroupName = radgroupcheck.GroupName ORD
> ER BY radgroupcheck.id': user at tmn.pt
> Tue Feb 9 16:36:04 2010: DEBUG: Radius::AuthFREERADIUSSQL looks for match with user at tmn.pt [user at tmn.pt]
> Tue Feb 9 16:36:04 2010: DEBUG: Radius::AuthFREERADIUSSQL ACCEPT: : user at tmn.pt [user at tmn.pt]
> Tue Feb 9 16:36:04 2010: DEBUG: AuthBy FREERADIUSSQL result: ACCEPT,
> Tue Feb 9 16:36:04 2010: DEBUG: Handling with Radius::AuthDYNADDRESS
> Tue Feb 9 16:36:04 2010: DEBUG: AuthBy DYNADDRESS result: ACCEPT,
> Tue Feb 9 16:36:04 2010: DEBUG: Access accepted for user at tmn.pt
> Tue Feb 9 16:36:04 2010: WARNING: No such attribute PoolHint
> Tue Feb 9 16:36:04 2010: DEBUG: Packet dump:
> *** Sending to 10.112.48.185 port 32882 ....
> Code: Access-Accept
> Identifier: 64
> Authentic: <214><188>V~<241>]"<195><157><195><143><170><246>G<185><149>
> Attributes:
> Framed-IP-Address = 255.255.255.254
> PoolHint = pool1
> Framed-IP-Address = 255.255.255.254
> PoolHint = pool1
>
> Tue Feb 9 16:36:04 2010: DEBUG: Packet dump:
> *** Received from 10.112.48.185 port 32882 ....
> Code: Accounting-Request
> Identifier: 65
> Authentic: O<15><165><3>DKs<180>N<192><173><241><249><25> <215>
> Attributes:
> User-Name = "user at tmn.pt"
> Service-Type = Framed-User
> NAS-IP-Address = 203.63.154.1
> NAS-Identifier = "203.63.154.11"
> NAS-Port = 1234
> NAS-Port-Type = Async
> Acct-Session-Id = "00001234"
> Acct-Status-Type = Start
> Called-Station-Id = "123456789"
> Calling-Station-Id = "987654321"
> Framed-IP-Address = 255.255.255.254
> Acct-Delay-Time = 0
> Called-Station-Id = "12345"
> Framed-Protocol = PPP
>
> Tue Feb 9 16:36:04 2010: DEBUG: Handling request with Handler 'Client-Identifier=WiFi'
> Tue Feb 9 16:36:04 2010: DEBUG: WAP_TMN Adding session for user at tmn.pt, 203.63.154.1, 1234
> Tue Feb 9 16:36:04 2010: DEBUG: do query is: 'DELETE FROM session WHERE NASIDENTIFIER='203.63.154.1' AND NASPORT=1234':
> Tue Feb 9 16:36:04 2010: DEBUG: do query is: 'INSERT INTO session (USERNAME, NASIDENTIFIER, NASPORT,ACCTSESSIONID, TIME_STAMP, FRAM
> EDIPADDRESS, NASPORTTYPE, SERVICETYPE) VALUES ('user at tmn.pt', '203.63.154.1', 1234, '00001234', 1265733364,'255.255.255.254', 'Async
> ', 'Framed-User')':
> Tue Feb 9 16:36:04 2010: DEBUG: Handling with Radius::AuthFREERADIUSSQL: local_db_wifi
> Tue Feb 9 16:36:04 2010: DEBUG: Handling accounting with Radius::AuthFREERADIUSSQL
> Tue Feb 9 16:36:04 2010: DEBUG: do query is: 'INSERT into radacct (AcctSessionId, AcctUniqueId, UserName, Realm, NASIPAddress, NASP
> ortId, NASPortType, AcctStartTime, AcctStopTime, AcctSessionTime, AcctAuthentic, ConnectInfo_start, ConnectInfo_stop, AcctInputOctet
> s, AcctOutputOctets, CalledStationId, CallingStationId, AcctTerminateCause, ServiceType, FramedProtocol, FramedIPAddress, AcctStartD
> elay, AcctStopDelay) values('00001234', '', '', '', '203.63.154.1', '1234', 'Async', '2010-02-09 16:36:04', NULL, '0', '', '', '', '
> 0', '0', '123456789', '987654321', '', 'Framed-User', 'PPP', '255.255.255.254', '0', '0')':
> Tue Feb 9 16:36:04 2010: DEBUG: AuthBy FREERADIUSSQL result: ACCEPT,
> Tue Feb 9 16:36:04 2010: DEBUG: Handling with Radius::AuthDYNADDRESS
> Tue Feb 9 16:36:04 2010: DEBUG: AuthBy DYNADDRESS result: ACCEPT,
> Tue Feb 9 16:36:04 2010: DEBUG: Accounting accepted
> Tue Feb 9 16:36:04 2010: DEBUG: Packet dump:
> *** Sending to 10.112.48.185 port 32882 ....
> Code: Accounting-Response
> Identifier: 65
> Authentic: <243><215>g@<208><152><3><250><210>C<6><166>.%<245>%
> Attributes:
> Tue Feb 9 16:36:04 2010: DEBUG: Packet dump:
> *** Received from 10.112.48.185 port 32882 ....
> Code: Accounting-Request
> Identifier: 66
> Authentic: 5<183><255><135><156><240>t$<180>(?_<199><10><192><219>
> Attributes:
> User-Name = "user at tmn.pt"
> Service-Type = Framed-User
> NAS-IP-Address = 203.63.154.1
> NAS-Identifier = "203.63.154.11"
> NAS-Port = 1234
> NAS-Port-Type = Async
> Acct-Session-Id = "00001234"
> Acct-Status-Type = Stop
> Called-Station-Id = "123456789"
> Calling-Station-Id = "987654321"
> Framed-IP-Address = 255.255.255.254
> Acct-Delay-Time = 0
> Acct-Session-Time = 1000
> Acct-Input-Octets = 20000
> Acct-Output-Octets = 30000
> Called-Station-Id = "12345"
> Framed-Protocol = PPP
>
> Tue Feb 9 16:36:04 2010: DEBUG: Handling request with Handler 'Client-Identifier=WiFi'
> Tue Feb 9 16:36:04 2010: DEBUG: WAP_TMN Deleting session for user at tmn.pt, 203.63.154.1, 1234
> Tue Feb 9 16:36:04 2010: DEBUG: do query is: 'DELETE FROM session WHERE NASIDENTIFIER='203.63.154.1' AND NASPORT=1234':
> Tue Feb 9 16:36:04 2010: DEBUG: Handling with Radius::AuthFREERADIUSSQL: local_db_wifi
> Tue Feb 9 16:36:04 2010: DEBUG: Handling accounting with Radius::AuthFREERADIUSSQL
> Tue Feb 9 16:36:04 2010: DEBUG: do query is: 'UPDATE radacct SET AcctStopTime = '2010-02-09 16:36:04', AcctSessionTime = '1000', Ac
> ctInputOctets = '20000', AcctOutputOctets = '30000', AcctTerminateCause = '', AcctStopDelay = '0', ConnectInfo_stop = '' WHERE AcctS
> essionId = '00001234' AND UserName = '' AND NASIPAddress = '203.63.154.1'':
> Tue Feb 9 16:36:04 2010: DEBUG: AuthBy FREERADIUSSQL result: ACCEPT,
> Tue Feb 9 16:36:04 2010: DEBUG: Handling with Radius::AuthDYNADDRESS
> Tue Feb 9 16:36:04 2010: DEBUG: do query is: 'UPDATE RADPOOL SET STATE=0,TIME_STAMP=1265733364 WHERE YIADDR='255.255.255.254'':
> Tue Feb 9 16:36:04 2010: DEBUG: AuthBy DYNADDRESS result: ACCEPT,
> Tue Feb 9 16:36:04 2010: DEBUG: Accounting accepted
> Tue Feb 9 16:36:04 2010: DEBUG: Packet dump:
> *** Sending to 10.112.48.185 port 32882 ....
> Code: Accounting-Response
> Identifier: 66
> Authentic: s<243>G<208>eX6<156>I<22><0><0><228><138><229><228>
> Attributes:
>
>
>
>
> -----Original Message-----
> From: Hugh Irvine [mailto:hugh at open.com.au]
> Sent: quarta-feira, 31 de Março de 2010 10:23
> To: Carlos Parada
> Cc: radiator at open.com.au; Carlos Rodrigues
> Subject: Re: [RADIATOR] Errors on database
>
>
> Hello Carlos -
>
> I will need to see a copy of the configuration file and a trace 4 debug showing what is happening.
>
> regards
>
> Hugh
>
>
> On 31 Mar 2010, at 00:34, Carlos Parada wrote:
>
>> Hi all,
>>
>> I'm using the FREERADIUSSQL AuthBy mechanism to authenticate users. In general, it is working ok; but, the first time I access to the DB I always get the following error.
>>
>> Tue Mar 30 14:17:31 2010: ERR: Execute failed for 'SELECT id, UserName, Attribute, Value, op FROM wapcheck WHERE Username=? ORDER BY id LIMIT 1 ': server closed the connection unexpectedly
>> This probably means the server terminated abnormally
>> before or while processing the request.
>>
>> I've googled this error and it seems related to the postgres database. However, logging the database I am not able to see any error. I have no clues about how to solve it.
>>
>> Anybody has any tip about how to solve this?
>>
>>
>> Regards,
>> Carlos Parada
>> _______________________________________________
>> radiator mailing list
>> radiator at open.com.au
>> http://www.open.com.au/mailman/listinfo/radiator
>
>
>
> 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.
> Includes support for reliable RADIUS transport (RadSec),
> and DIAMETER translation agent.
> -
> 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.
>
>
>
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.
Includes support for reliable RADIUS transport (RadSec),
and DIAMETER translation agent.
-
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.
_______________________________________________
radiator mailing list
radiator at open.com.au
http://www.open.com.au/mailman/listinfo/radiator
More information about the radiator
mailing list