[Bug 1081509] Re: freeradius + mysql fails to start

[Florin Andrei]

Wow, this is an old bug, still not fixed. I've stumbled upon this exact
same problem last week. It's due to the fact that the freeradius service
starts way too early.

Happens every time on Ubuntu 14.04.

apt-get update
apt-get dist-upgrade
apt-get install freeradius freeradius-mysql

I had the MySQL server already installed at this point, pulled as
dependency for another package

Configure FreeRadius to use MySQL for authorization.

reboot

Now check syslog:

#################################
Sep  9 12:17:55 yubi1 freeradius[970]: rlm_sql (sql): Driver rlm_sql_mysql (module rlm_sql_mysql) loaded and linked
Sep  9 12:17:55 yubi1 freeradius[970]: rlm_sql (sql): Attempting to connect to radius at localhost:/radius
Sep  9 12:17:55 yubi1 freeradius[970]: rlm_sql (sql): Attempting to connect rlm_sql_mysql #0
Sep  9 12:17:55 yubi1 freeradius[970]: rlm_sql_mysql: Starting connect to MySQL server for #0
Sep  9 12:17:55 yubi1 freeradius[970]: rlm_sql_mysql: Couldn't connect socket to MySQL server radius at localhost:radius
Sep  9 12:17:55 yubi1 freeradius[970]: rlm_sql_mysql: Mysql error 'Can't connect to local MySQL server through socket '/var/run/mysqld/mysqld.sock' (2)'
Sep  9 12:17:55 yubi1 freeradius[970]: rlm_sql (sql): Failed to connect DB handle #0
Sep  9 12:17:55 yubi1 freeradius[970]: Loaded virtual server <default>
Sep  9 12:17:55 yubi1 freeradius[970]: Loaded virtual server inner-tunnel
Sep  9 12:17:55 yubi1 freeradius[970]:  ... adding new socket proxy address * port 36585
Sep  9 12:17:55 yubi1 freeradius[970]: Ready to process requests.
Sep  9 12:17:55 yubi1 kernel: [    4.588328] vboxsf: Successfully loaded version 4.3.14 (interface 0x00010004)
Sep  9 12:17:56 yubi1 freeradius[1256]: rlm_sql (sql): Driver rlm_sql_mysql (module rlm_sql_mysql) loaded and linked
Sep  9 12:17:56 yubi1 freeradius[1256]: rlm_sql (sql): Attempting to connect to radius at localhost:/radius
Sep  9 12:17:56 yubi1 freeradius[1256]: rlm_sql (sql): Attempting to connect rlm_sql_mysql #0
Sep  9 12:17:56 yubi1 freeradius[1256]: rlm_sql_mysql: Starting connect to MySQL server for #0
Sep  9 12:17:56 yubi1 freeradius[1256]: rlm_sql (sql): Connected new DB handle, #0
Sep  9 12:17:56 yubi1 freeradius[1256]: rlm_sql (sql): Attempting to connect rlm_sql_mysql #1
Sep  9 12:17:56 yubi1 freeradius[1256]: rlm_sql_mysql: Starting connect to MySQL server for #1
Sep  9 12:17:56 yubi1 freeradius[1256]: rlm_sql (sql): Connected new DB handle, #1
Sep  9 12:17:56 yubi1 freeradius[1256]: rlm_sql (sql): Attempting to connect rlm_sql_mysql #2
Sep  9 12:17:56 yubi1 freeradius[1256]: rlm_sql_mysql: Starting connect to MySQL server for #2
Sep  9 12:17:56 yubi1 freeradius[1256]: rlm_sql (sql): Connected new DB handle, #2
Sep  9 12:17:56 yubi1 freeradius[1256]: rlm_sql (sql): Attempting to connect rlm_sql_mysql #3
Sep  9 12:17:56 yubi1 freeradius[1256]: rlm_sql_mysql: Starting connect to MySQL server for #3
Sep  9 12:17:56 yubi1 freeradius[1256]: rlm_sql (sql): Connected new DB handle, #3
Sep  9 12:17:56 yubi1 freeradius[1256]: rlm_sql (sql): Attempting to connect rlm_sql_mysql #4
Sep  9 12:17:56 yubi1 freeradius[1256]: rlm_sql_mysql: Starting connect to MySQL server for #4
Sep  9 12:17:56 yubi1 freeradius[1256]: rlm_sql (sql): Connected new DB handle, #4
Sep  9 12:17:56 yubi1 freeradius[1256]: Loaded virtual server <default>
Sep  9 12:17:56 yubi1 freeradius[1256]: Loaded virtual server inner-tunnel
Sep  9 12:17:56 yubi1 freeradius[1263]: Failed binding to authentication address * port 1812: Address already in use 
Sep  9 12:17:56 yubi1 freeradius[1263]: /etc/freeradius/radiusd.conf[240]: Error binding to port for 0.0.0.0 port 1812
Sep  9 12:17:57 yubi1 /etc/mysql/debian-start[1313]: Upgrading MySQL tables if necessary.
Sep  9 12:17:57 yubi1 /etc/mysql/debian-start[1316]: /usr/bin/mysql_upgrade: the '--basedir' option is always ignored
Sep  9 12:17:57 yubi1 /etc/mysql/debian-start[1316]: Looking for 'mysql' as: /usr/bin/mysql
Sep  9 12:17:57 yubi1 /etc/mysql/debian-start[1316]: Looking for 'mysqlcheck' as: /usr/bin/mysqlcheck
Sep  9 12:17:57 yubi1 /etc/mysql/debian-start[1316]: This installation of MySQL is already upgraded to 5.5.38, use --force if you still need to run mysql_upgrade
Sep  9 12:17:57 yubi1 /etc/mysql/debian-start[1327]: Checking for insecure root accounts.
Sep  9 12:17:57 yubi1 /etc/mysql/debian-start[1332]: Triggering myisam-recover for all MyISAM tables
#################################

As it's clear from the logs, the problem is that the FreeRadius service
starts before MySQL, but FreeRadius depends on MySQL.

It should start after MySQL, just like many other services do.

This is the relevant software:

# dpkg -l | grep -e freeradius -e mysql
ii  freeradius                          2.1.12+dfsg-1.2ubuntu8        amd64        high-performance and highly configurable RADIUS server
ii  freeradius-common                   2.1.12+dfsg-1.2ubuntu8        all          FreeRADIUS common files
ii  freeradius-mysql                    2.1.12+dfsg-1.2ubuntu8        amd64        MySQL module for FreeRADIUS server
ii  freeradius-utils                    2.1.12+dfsg-1.2ubuntu8        amd64        FreeRADIUS client utilities
ii  libdbd-mysql-perl                   4.025-1                       amd64        Perl5 database interface to the MySQL database
ii  libfreeradius2                      2.1.12+dfsg-1.2ubuntu8        amd64        FreeRADIUS shared library
ii  libmysqlclient18:amd64              5.5.38-0ubuntu0.14.04.1       amd64        MySQL database client library
ii  mysql-client-5.5                    5.5.38-0ubuntu0.14.04.1       amd64        MySQL database client binaries
ii  mysql-client-core-5.5               5.5.38-0ubuntu0.14.04.1       amd64        MySQL database core client binaries
ii  mysql-common                        5.5.38-0ubuntu0.14.04.1       all          MySQL database common files, e.g. /etc/mysql/my.cnf
ii  mysql-server                        5.5.38-0ubuntu0.14.04.1       all          MySQL database server (metapackage depending on the latest version)
ii  mysql-server-5.5                    5.5.38-0ubuntu0.14.04.1       amd64        MySQL database server binaries and system database setup
ii  mysql-server-core-5.5               5.5.38-0ubuntu0.14.04.1       amd64        MySQL database server binaries
ii  php5-mysql                          5.5.9+dfsg-1ubuntu4.3         amd64        MySQL module for php5

** Changed in: freeradius (Ubuntu)
       Status: Expired => New

-- 
You received this bug notification because you are a member of Ubuntu
Server Team, which is subscribed to freeradius in Ubuntu.
https://bugs.launchpad.net/bugs/1081509

Title:
  freeradius + mysql fails to start

To manage notifications about this bug go to:
https://bugs.launchpad.net/ubuntu/+source/freeradius/+bug/1081509/+subscriptions