freeradius-1.1.6 - mysql failover issue - bus error -

[Francesco Cristofori]

Hi all,
I'm setting up module fail-over for mysql backend following the guide from the wiki, but something goes wrong.
I included two sql.conf (mysql1.conf and mysql2.conf) in the "modules" section and radiusd -X reports the two files are included, but I only see the parameters from the first file get loaded and everything stops with "bus error" when trying to connect to the server.

I checked name resolution, mysql user/password, network reachability and everything it's ok.
I also set a tcpdump session on mysql1 but no packets for mysql are coming in.
Then I straced radiusd execution and I noticed it fails after reading /etc/hosts (?!?).

Here's the relevant output from radiusd -X:

Module: Loaded SQL 
 sql: driver = "rlm_sql_mysql"
 sql: server = "mysql1.satcom.it"
 sql: port = "3306"
 sql: login = "radius"
 sql: password = "radius"
 sql: radius_db = "radius"
 sql: nas_table = "nas"
 sql: sqltrace = no
 sql: sqltracefile = "/var/log/freeradius/sqltrace.sql"
 sql: readclients = no
 sql: deletestalesessions = yes
 sql: num_sql_socks = 100
 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,radgroupcheck.op  FROM radgroupcheck,usergroup WHERE usergroup.Username = '%{SQL-User-Name}' AND usergroup.GroupName = radgroupcheck.GroupName ORDER BY radgroupcheck.id"
 sql: authorize_group_reply_query = "SELECT radgroupreply.id,radgroupreply.GroupName,radgroupreply.Attribute,radgroupreply.Value,radgroupreply.op  FROM radgroupreply,usergroup WHERE usergroup.Username = '%{SQL-User-Name}' AND usergroup.GroupName = radgroupreply.GroupName ORDER BY radgroupreply.id"
 sql: accounting_onoff_query = "UPDATE radacct SET AcctStopTime='%S', AcctSessionTime=unix_timestamp('%S') - unix_timestamp(AcctStartTime), 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, 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('%S',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')"
 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) values('%{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}', '', '%{Service-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 = '%{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}'"
 sql: accounting_stop_query_alt = "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('%S', INTERVAL (%{Acct-Session-Time:-0} + %{Acct-Delay-Time:-0}) SECOND), '%S', '%{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}')"
 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, FramedProtocol 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-Password}', '%{reply:Packet-Type}', NOW())"
 sql: safe-characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /"
rlm_sql (mysql1): Driver rlm_sql_mysql (module rlm_sql_mysql) loaded and linked
rlm_sql (mysql1): Attempting to connect to radius at mysql1.satcom.it:3306/radius
rlm_sql (mysql1): starting 0
rlm_sql (mysql1): Attempting to connect rlm_sql_mysql #0
rlm_sql_mysql: Starting connect to MySQL server for #0
Bus error


Here's the relevant output from strace radiusd -X :

write(1, "rlm_sql (mysql1): starting 0\n", 29rlm_sql (mysql1): starting 0
) = 29
time(NULL)                              = 1183449009
time(NULL)                              = 1183449009
write(1, "rlm_sql (mysql1): Attempting to "..., 57rlm_sql (mysql1): Attempting to connect rlm_sql_mysql #0
) = 57
time(NULL)                              = 1183449009
write(1, "rlm_sql_mysql: Starting connect "..., 55rlm_sql_mysql: Starting connect to MySQL server for #0
) = 55
open("/etc/services", O_RDONLY)         = 5
fcntl64(5, F_GETFD)                     = 0
fcntl64(5, F_SETFD, FD_CLOEXEC)         = 0
fstat64(5, {st_mode=S_IFREG|0644, st_size=18274, ...}) = 0
mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xf7a6a000
read(5, "# Network services, Internet sty"..., 8192) = 8192
read(5, "otus Note\nlotusnote\t1352/udp\tlot"..., 8192) = 8192
close(5)                                = 0
munmap(0xf7a6a000, 8192)                = 0
rt_sigaction(SIGPIPE, {SIG_IGN}, {SIG_DFL}, 0xf7b188f8, 4294967295) = 0
stat64("/etc/mysql/my.cnf", {st_mode=S_IFREG|0644, st_size=3636, ...}) = 0
open("/etc/mysql/my.cnf", O_RDONLY|O_LARGEFILE) = 5
fstat64(5, {st_mode=S_IFREG|0644, st_size=3636, ...}) = 0
mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xf7a6a000
read(5, "#\n# The MySQL database server co"..., 8192) = 3636
open("/etc/mysql/conf.d/", O_RDONLY|O_NONBLOCK|O_LARGEFILE|O_DIRECTORY|0x4) = 6
fstat64(6, {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
fcntl64(6, F_SETFD, FD_CLOEXEC)         = 0
getdents64(6, /* 2 entries */, 8192)    = 48
getdents64(6, /* 0 entries */, 8192)    = 0
close(6)                                = 0
read(5, "", 8192)                       = 0
close(5)                                = 0
munmap(0xf7a6a000, 8192)                = 0
stat64("/root/.my.cnf", 0xffc8c908)     = -1 ENOENT (No such file or directory)
stat64("/usr/etc/my.cnf", 0xffc8c908)   = -1 ENOENT (No such file or directory)
socket(PF_INET, SOCK_STREAM, IPPROTO_IP) = 5
fcntl64(5, F_SETFL, O_RDONLY)           = 0
fcntl64(5, F_GETFL)                     = 0x2 (flags O_RDWR)
open("/etc/hosts", O_RDONLY)            = 6
fcntl64(6, F_GETFD)                     = 0
fcntl64(6, F_SETFD, FD_CLOEXEC)         = 0
fstat64(6, {st_mode=S_IFREG|0644, st_size=392, ...}) = 0
mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xf7a6a000
read(6, "127.0.0.1\tlocalhost\n10.3.0.170\tr"..., 8192) = 392
--- SIGBUS (Bus error) @ 0 (0) ---
+++ killed by SIGBUS +++


Any hints?

Thanks in advance,
	Francesco Cristofori.