no start of radiusd after reboot : mysql connection error
Hello, I use freeradius-1.1.3-1.2.el5 and freeradius-mysql-1.1.3-1.2.el5. the mysql database (mysql-server-5.0.22-2.1.0.1) is hosted on a remote host (both centos5). When I use /etc/init.d/radiusd as root it starts up correctly. But when the service is launched at boot time, I get this error-log : Wed Feb 6 16:17:46 2008 : Info: Using deprecated naslist file. Support for this will go away soon. Wed Feb 6 16:17:46 2008 : Info: rlm_exec: Wait=yes but no output defined. Did you mean output=none? Wed Feb 6 16:17:46 2008 : Info: rlm_sql (sql): Driver rlm_sql_mysql (module rlm_sql_mysql) loaded and linked Wed Feb 6 16:17:46 2008 : Info: rlm_sql (sql): Attempting to connect to radius@192.168.1.1:/radius Wed Feb 6 16:17:46 2008 : Info: rlm_sql_mysql: Starting connect to MySQL server for #0 Wed Feb 6 16:17:49 2008 : Error: rlm_sql_mysql: Couldn't connect socket to MySQL server radius@192.168.1.1:radius Wed Feb 6 16:17:49 2008 : Error: rlm_sql_mysql: Mysql error 'Can't connect to MySQL server on '192.168.1.1' (113)' Wed Feb 6 16:17:49 2008 : Error: rlm_sql (sql): Failed to connect DB handle #0 Wed Feb 6 16:17:49 2008 : Info: rlm_sql (sql): There are no DB handles to use! skipped 5, tried to connect 0 Wed Feb 6 16:17:49 2008 : Error: rlm_sql (sql): generate_sql_clients() returned error Wed Feb 6 16:17:49 2008 : Error: radiusd.conf[14]: sql: Module instantiation failed. Wed Feb 6 16:17:49 2008 : Error: radiusd.conf[1844] Unknown module "sql". Wed Feb 6 16:17:49 2008 : Error: radiusd.conf[1773] Failed to parse authorize section. I set a tcpdump on the mysql-server host, and during the boot of my freeradius server, I see no traffic comming from freeradius host. There is no reject in the firewall. I've tried to put the radius rc.d script in S99 to start it as late as possible, but nothing changes. I also noticed that it doesen't seem to retry to connect to the database later. Or is it after a long time ? Is this a bug ? Where is the retry time configured (I cant try to set up to 5 seconds) ? Thanks for answers Laetitia.
mailinglists wrote:
Hello, I use freeradius-1.1.3-1.2.el5 and freeradius-mysql-1.1.3-1.2.el5. the mysql database (mysql-server-5.0.22-2.1.0.1) is hosted on a remote host (both centos5). When I use /etc/init.d/radiusd as root it starts up correctly. But when the service is launched at boot time, I get this error-log :
The server is configured with "user" and "group" in radiusd.conf, and that user/group does not have permission to talk to the MySQL server.
I set a tcpdump on the mysql-server host, and during the boot of my freeradius server, I see no traffic comming from freeradius host. There is no reject in the firewall. I've tried to put the radius rc.d script in S99 to start it as late as possible, but nothing changes.
It's a permission problem, not a boot order problem.
I also noticed that it doesen't seem to retry to connect to the database later. Or is it after a long time ? Is this a bug ? Where is the retry time configured (I cant try to set up to 5 seconds) ?
Re-trying when it doesn't have permission to connect won't help. Alan DeKok.
Alan DeKok a écrit :
mailinglists wrote:
Hello, I use freeradius-1.1.3-1.2.el5 and freeradius-mysql-1.1.3-1.2.el5. the mysql database (mysql-server-5.0.22-2.1.0.1) is hosted on a remote host (both centos5). When I use /etc/init.d/radiusd as root it starts up correctly. But when the service is launched at boot time, I get this error-log :
The server is configured with "user" and "group" in radiusd.conf, and that user/group does not have permission to talk to the MySQL server.
I set a tcpdump on the mysql-server host, and during the boot of my freeradius server, I see no traffic comming from freeradius host. There is no reject in the firewall. I've tried to put the radius rc.d script in S99 to start it as late as possible, but nothing changes.
It's a permission problem, not a boot order problem.
I also noticed that it doesen't seem to retry to connect to the database later. Or is it after a long time ? Is this a bug ? Where is the retry time configured (I cant try to set up to 5 seconds) ?
Re-trying when it doesn't have permission to connect won't help.
Alan DeKok. - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
Do you mean that I must allow my user on the mysql server ? I don't think so, since there is no traffic from the freeradius to mysql at boot time. And furthermore, the user *is* allowed to connect to database from the free-radius host There are perhaps permissions problems on the freeradius hosts, to launch a particular process ? Please can you telle me how I can allow user/group to talk to the MySQL server ? thanks laetitia
Hi,
Do you mean that I must allow my user on the mysql server ? I don't think so, since there is no traffic from the freeradius to mysql at boot time. And furthermore, the user *is* allowed to connect to database from the free-radius host There are perhaps permissions problems on the freeradius hosts, to launch a particular process ? Please can you telle me how I can allow user/group to talk to the MySQL server ?
sounds like SELinux to me - check your SELinux security settings and their logs - if you are enforcing, your logs will show the failure of this connection alan
A.L.M.Buxey@lboro.ac.uk a écrit :
Hi,
Do you mean that I must allow my user on the mysql server ? I don't think so, since there is no traffic from the freeradius to mysql at boot time. And furthermore, the user *is* allowed to connect to database from the free-radius host There are perhaps permissions problems on the freeradius hosts, to launch a particular process ? Please can you telle me how I can allow user/group to talk to the MySQL server ?
sounds like SELinux to me - check your SELinux security settings and their logs - if you are enforcing, your logs will show the failure of this connection
alan - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
Yes I already check that, SELINUX is disabled.... [root@ronsard ~]# cat /etc/selinux/config SELINUX=disabled SELINUXTYPE=targeted SETLOCALDEFS=0 another idea ? perhaps something with permissions on binaries ? Thanks
Hi,
Yes I already check that, SELINUX is disabled....
[root@ronsard ~]# cat /etc/selinux/config SELINUX=disabled SELINUXTYPE=targeted SETLOCALDEFS=0
another idea ? perhaps something with permissions on binaries ?
what happens if you start the daemon from the command line with radiusd -x (small x, not the big debug X! iirc, this runs it with the configured priviledges rather than with root) otherwise, as root, 'su' to the account you are running the service as eg su - radiusd and run the daemon. check what it can or cannot read! alan
--On Thursday, February 07, 2008 10:24:11 AM +0100 Alan DeKok <aland@deployingradius.com> wrote:
mailinglists wrote:
Hello, I use freeradius-1.1.3-1.2.el5 and freeradius-mysql-1.1.3-1.2.el5. the mysql database (mysql-server-5.0.22-2.1.0.1) is hosted on a remote host (both centos5). When I use /etc/init.d/radiusd as root it starts up correctly. But when the service is launched at boot time, I get this error-log :
The server is configured with "user" and "group" in radiusd.conf, and that user/group does not have permission to talk to the MySQL server.
Close, but no cigar. The OP wrote:
Wed Feb 6 16:17:49 2008 : Error: rlm_sql_mysql: Mysql error 'Can't connect to MySQL server on '192.168.1.1' (113)'
Errno 113 is EHOSTUNREACH. Either there is no route to the MySQL server, or it locally-connected and not answering ARP's, or something is filtering the traffic. Check your routing table and the filters on both machines and any network devices you might have between them. -- Jeffrey T. Hutzelman (N3NHS) <jhutz+@cmu.edu> Carnegie Mellon University - Pittsburgh, PA
Jeffrey Hutzelman a écrit :
Wed Feb 6 16:17:49 2008 : Error: rlm_sql_mysql: Mysql error 'Can't connect to MySQL server on '192.168.1.1' (113)'
Errno 113 is EHOSTUNREACH. Either there is no route to the MySQL server, or it locally-connected and not answering ARP's, or something is filtering the traffic. Check your routing table and the filters on both machines and any network devices you might have between them.
-- Jeffrey T. Hutzelman (N3NHS) <jhutz+@cmu.edu> Carnegie Mellon University - Pittsburgh, PA
- List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
The thing is that just after boot, when launched as root with /etc/init.d/radiusd start, it works ! But I tested something interesting : I added a ping test in the /etc/init.d/radiusd script : case "$1" in start) echo "test : ping BDD to see if connection is available" ping -c 2 bdd.domain.com echo "test result : $?" echo -n $"Starting RADIUS server: " daemon $RADIUSD -y ... And it worked ! (so network is ok, since the DNS resolution works...) But without a ping, nothing comes in tcpdump on the BDD server. So, its like I had to "wake up" the network functions for freeradius before being able to talk to the database host. I must precise that a lot of other network services are launched - and work fine - on the freeradius host before freeradius (dhcp, sendmail, etc). So any new idea ? Thank you very much for your precious help ! Laetitia
I'm sorry to bother you with debug log files, but I really dont' see what to do... before the log... I summarize my problem : After reboot, freeradius does'nt start, and says this is because it could'nt reach the mysql database. But it doesn't even tries to contact it (networkingly-speaking : tcpdump sees nothing). Just after reboot, if root runs "/etc/init.d/radiusd start", freeradius starts OK, and contacts correctly the database. If I add a "ping database.domain.com" in the /etc/init.d/radiusd just before starting radiusd, it works, even at boot time !! (but it's really a dirty and ugly a solution, so I cant' resolv myself to such an issue !!!) I've tried to wait 5 minutes to see if there is some retry time, but noting happens, since radiusd is just not running.... so here is my debug file (only the mysql part).... if someone can help me, it would be nice (or I'll have to go back to my dirty-ugly issue.....I d'ont want to !) Module: Loaded SQL sql: driver = "rlm_sql_mysql" sql: server = "192.168.1.1" sql: port = "" sql: login = "radius" sql: password = "radius" sql: radius_db = "radius" sql: nas_table = "nas" sql: sqltrace = yes --> I don't see nothing.... sql: sqltracefile = "/var/log/radius/sqltrace.sql" sql: readclients = yes sql: deletestalesessions = yes sql: num_sql_socks = 5 sql: sql_user_name = "%{User-Name}" sql: default_user_profile = "" sql: query_on_not_found = no sql: authorize_check_query = "SELECT id, UserName, Attribute, Value, op FROM radcheck WHERE Username = '%{SQL-User -Name}' ORDER BY id" sql: authorize_reply_query = "SELECT id, UserName, Attribute, Value, op FROM radreply WHERE Username = '%{SQL-User -Name}' ORDER BY id" sql: authorize_group_check_query = "SELECT radgroupcheck.id,radgroupcheck.GroupName,radgroupcheck.Attribute,radgroupcheck.Value,radgro upcheck.op FROM radgroupcheck,usergroup WHERE usergroup.Username = '%{SQL-User-Name}' AND usergroup.GroupName = radgroupcheck.GroupNam e ORDER BY radgroupcheck.id" sql: authorize_group_reply_query = "SELECT radgroupreply.id,radgroupreply.GroupName,radgroupreply.Attribute,radgroupreply.Value,radgro upreply.op FROM radgroupreply,usergroup WHERE usergroup.Username = '%{SQL-User-Name}' AND usergroup.GroupName = radgroupreply.GroupNam e ORDER BY radgroupreply.id" sql: accounting_onoff_query = "UPDATE radacct SET AcctStopTime='%S', AcctSessionTime=unix_timestamp('%S') - unix_timestamp(AcctStartTi me), AcctTerminateCause='%{Acct-Terminate-Cause}', AcctStopDelay = '%{Acct-Delay-Time}' WHERE AcctSessionTime=0 AND AcctStopTime=0 AND NASIPAddress= '%{NAS-IP-Address}' AND AcctStartTime <= '%S'" sql: accounting_update_query = "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}' " sql: accounting_update_query_alt = "INSERT into radacct (AcctSessionId, AcctUniqueId, UserName, Realm, NASIPAddress, NASPortId, NASPor tType, AcctStartTime, AcctSessionTime, AcctAuthentic, ConnectInfo_start, AcctInputOctets, AcctOutputOctets, CalledStationId, CallingSta tionId, 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('%S',INTERVAL (%{Acct-Session-Time:-0} + %{Ac ct-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')" sql: accounting_start_query = "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) val ues('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}', '%{SQL-User-Name}', '%{Realm}', '%{NAS-IP-Address}', '%{NAS-Port}', '%{NAS-Port- Type}', '%S', '0', '0', '%{Acct-Authentic}', '%{Connect-Info}', '', '0', '0', '%{Called-Station-Id}', '%{Calling-Station-Id}', '', '%{S ervice-Type}', '%{Framed-Protocol}', '%{Framed-IP-Address}', '%{Acct-Delay-Time}', '0')" sql: accounting_start_query_alt = "UPDATE radacct SET AcctStartTime = '%S', AcctStartDelay = '%{Acct-Delay-Time}', ConnectInfo_start = '%{Connect-Info}' WHERE AcctSessionId = '%{Acct-Session-Id}' AND UserName = '%{SQL-User-Name}' AND NASIPAddress = '%{NAS-IP-Address}'" sql: accounting_stop_query = "UPDATE radacct SET AcctStopTime = '%S', AcctSessionTime = '%{Acct-Session-Time}', AcctInputOctets = '%{A cct-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 NA SIPAddress = '%{NAS-IP-Address}'" sql: accounting_stop_query_alt = "INSERT into radacct (AcctSessionId, AcctUniqueId, UserName, Realm, NASIPAddress, NASPortId, NASPortT ype, AcctStartTime, AcctStopTime, AcctSessionTime, AcctAuthentic, ConnectInfo_start, ConnectInfo_stop, AcctInputOctets, AcctOutputOctet s, 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-Po rt-Type}', DATE_SUB('%S', INTERVAL (%{Acct-Session-Time:-0} + %{Acct-Delay-Time:-0}) SECOND), '%S', '%{Acct-Session-Time}', '%{Acct-Aut hentic}', '', '%{Connect-Info}', '%{Acct-Input-Octets}', '%{Acct-Output-Octets}', '%{Called-Station-Id}', '%{Calling-Station-Id}', '%{A cct-Terminate-Cause}', '%{Service-Type}', '%{Framed-Protocol}', '%{Framed-IP-Address}', '0', '%{Acct-Delay-Time}')" sql: group_membership_query = "SELECT GroupName FROM usergroup WHERE UserName='%{SQL-User-Name}'" sql: connect_failure_retry_delay = 60 sql: simul_count_query = "" sql: simul_verify_query = "SELECT RadAcctId, AcctSessionId, UserName, NASIPAddress, NASPortId, FramedIPAddress, CallingStationId, Fram edProtocol FROM radacct WHERE UserName='%{SQL-User-Name}' AND AcctStopTime = 0" sql: postauth_query = "INSERT into radpostauth (id, user, pass, reply, date) values ('', '%{User-Name}', '%{User-Password:-Chap-Passwo rd}', '%{reply:Packet-Type}', NOW())" sql: safe-characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /" rlm_sql (sql): Driver rlm_sql_mysql (module rlm_sql_mysql) loaded and linked rlm_sql (sql): Attempting to connect to radius@192.168.1.1:/radius rlm_sql (sql): starting 0 rlm_sql (sql): Attempting to connect rlm_sql_mysql #0 rlm_sql_mysql: Starting connect to MySQL server for #0 rlm_sql_mysql: Couldn't connect socket to MySQL server radius@192.168.1.1:radius rlm_sql_mysql: Mysql error 'Can't connect to MySQL server on '192.168.1.1' (113)' rlm_sql (sql): Failed to connect DB handle #0 rlm_sql (sql): starting 1 rlm_sql (sql): starting 2 rlm_sql (sql): starting 3 rlm_sql (sql): starting 4 rlm_sql (sql): Failed to connect to any SQL server. rlm_sql (sql): - generate_sql_clients rlm_sql (sql): Query: SELECT * FROM nas rlm_sql (sql): Ignoring unconnected handle 4.. rlm_sql (sql): Ignoring unconnected handle 3.. rlm_sql (sql): Ignoring unconnected handle 2.. rlm_sql (sql): Ignoring unconnected handle 1.. rlm_sql (sql): Ignoring unconnected handle 0.. rlm_sql (sql): There are no DB handles to use! skipped 5, tried to connect 0 rlm_sql (sql): generate_sql_clients() returned error rlm_sql (sql): Closing sqlsocket 4 rlm_sql (sql): Closing sqlsocket 3 rlm_sql (sql): Closing sqlsocket 2 rlm_sql (sql): Closing sqlsocket 1 rlm_sql (sql): Closing sqlsocket 0 radiusd.conf[14]: sql: Module instantiation failed. radiusd.conf[1844] Unknown module "sql". radiusd.conf[1773] Failed to parse authorize section. Sorry again, and thanks in advance for help ! Laetitia
mailinglists wrote:
After reboot, freeradius does'nt start, and says this is because it could'nt reach the mysql database. But it doesn't even tries to contact it (networkingly-speaking : tcpdump sees nothing). Just after reboot, if root runs "/etc/init.d/radiusd start", freeradius starts OK, and contacts correctly the database. If I add a "ping database.domain.com" in the /etc/init.d/radiusd just before starting radiusd, it works, even at boot time !! (but it's really a dirty and ugly a solution, so I cant' resolv myself to such an issue !!!)
It looks to me like it's a networking issue on that machine. The "ping" shouldn't effect anything... but it does. FreeRADIUS is at the mercy of the networking stack && the MySQL libraries. I don't think there's anything that can be done in FreeRADIUS to fix that. Alan DeKok.
Alan DeKok a écrit :
mailinglists wrote:
After reboot, freeradius does'nt start, and says this is because it could'nt reach the mysql database. But it doesn't even tries to contact it (networkingly-speaking : tcpdump sees nothing). Just after reboot, if root runs "/etc/init.d/radiusd start", freeradius starts OK, and contacts correctly the database. If I add a "ping database.domain.com" in the /etc/init.d/radiusd just before starting radiusd, it works, even at boot time !! (but it's really a dirty and ugly a solution, so I cant' resolv myself to such an issue !!!)
It looks to me like it's a networking issue on that machine. The "ping" shouldn't effect anything... but it does.
FreeRADIUS is at the mercy of the networking stack && the MySQL libraries. I don't think there's anything that can be done in FreeRADIUS to fix that
OK, I'm not expert enough in networking to debug that. So I come back to my dirty solution. I add the following line to the /etc/init.d/radiusd : start) # Palliatif au pb du non-demarrage de radiusd apres reboot # cf freeradius-users@lists.freeradius.org thread "no start of radiusd after reboot : mysql connection error" ping -c 1 ntp.domain.com echo -n $"Starting RADIUS server: " ... And it works....... Thank you for your help, bye Laetitia
Hi,
I add the following line to the /etc/init.d/radiusd : start) # Palliatif au pb du non-demarrage de radiusd apres reboot # cf freeradius-users@lists.freeradius.org thread "no start of radiusd after reboot : mysql connection error" ping -c 1 ntp.domain.com
echo -n $"Starting RADIUS server: " ...
hmmm, such a wierd setting requirement hints at the actual network interface needing a little more time until it is alive. this may point the finger away from the server and onto the network switch/router that it is connected to instead.... so you have eg 'spanning-tree portfast' configured on the port that the server is connected to? if not, you will have to wait up to 30 seconds after the network interface comes up before you are able to send/receive network packets. alan
participants (4)
-
A.L.M.Buxey@lboro.ac.uk -
Alan DeKok -
Jeffrey Hutzelman -
mailinglists