> Please provide complete proxy.conf and debugging output while doing 2 auth > attempts.
Attached are output from debug upon start up as well as 2 auth requests and the proxy.conf file I used. I am having the same problem on my test servers as I do in my production servers. It appears as though none of the servers I am proxying to are getting marked as dead, therefore it never fails over to the next server listed in the proxy file. I have ran several previous versions of FR in production and test and have always seen in the radius logs when home servers were marked as dead. I am not sure if it is a config issue or with something I may have broke when I compiled the servers. All of the servers are built pretty much the same. I used radtest to proxy the requests using: ./radtest [EMAIL PROTECTED] test localhost:1812 0 XXXXXXXXXXX Thanks, David
proxy.conf
Description: Binary data
Starting FreeRADIUS:Starting - reading configuration files ...
reread_config: reading radiusd.conf
Config: including file: /etc/raddb/proxy.conf
Config: including file: /etc/raddb/clients.conf
Config: including file: /etc/raddb/snmp.conf
Config: including file: /etc/raddb/mssql-auth.conf
Config: including file: /etc/raddb/mssql-acct.conf
main: prefix = "/opt/freeradius"
main: localstatedir = "/var"
main: logdir = "/var/log/radius"
main: libdir = "/opt/freeradius/lib"
main: radacctdir = "/var/log/radius/radacct"
main: hostname_lookups = no
main: snmp = yes
main: max_request_time = 9
main: cleanup_delay = 5
main: max_requests = 1024
main: delete_blocked_requests = 0
main: port = 1812
main: allow_core_dumps = no
main: log_stripped_names = no
main: log_file = "/var/log/radius/radius.log"
main: log_auth = yes
main: log_auth_badpass = yes
main: log_auth_goodpass = yes
main: pidfile = "/var/run/radiusd/radiusd.pid"
main: user = "radiusd"
main: group = "radiusd"
main: usercollide = no
main: lower_user = "no"
main: lower_pass = "no"
main: nospace_user = "no"
main: nospace_pass = "no"
main: checkrad = "/opt/freeradius/sbin/checkrad"
main: proxy_requests = yes
proxy: retry_delay = 5
proxy: retry_count = 3
proxy: synchronous = no
proxy: default_fallback = yes
proxy: dead_time = 120
proxy: post_proxy_authorize = yes
proxy: wake_all_if_all_dead = no
security: max_attributes = 200
security: reject_delay = 1
security: status_server = yes
main: debug_level = 0
read_config_files: reading dictionary
read_config_files: reading naslist
read_config_files: reading clients
read_config_files: reading realms
radiusd: entering modules setup
Module: Library search path is /opt/freeradius/lib
Module: Loaded expr
Module: Instantiated expr (expr)
Module: Loaded PAP
pap: encryption_scheme = "crypt"
Module: Instantiated pap (pap)
Module: Loaded preprocess
preprocess: huntgroups = "/etc/raddb/huntgroups"
preprocess: hints = "/etc/raddb/hints"
preprocess: with_ascend_hack = no
preprocess: ascend_channels_per_line = 23
preprocess: with_ntdomain_hack = no
preprocess: with_specialix_jetstream_hack = no
preprocess: with_cisco_vsa_hack = no
Module: Instantiated preprocess (preprocess)
Module: Loaded realm
realm: format = "suffix"
realm: delimiter = "@"
realm: ignore_default = no
realm: ignore_null = no
Module: Instantiated realm (suffix)
Module: Loaded files
files: usersfile = "/etc/raddb/users"
files: acctusersfile = "/etc/raddb/acct_users"
files: preproxy_usersfile = "/etc/raddb/preproxy_users"
files: compat = "no"
Module: Instantiated files (files)
Module: Loaded SQL
sql: driver = "rlm_sql_unixodbc"
sql: server = "10.1.1.72"
sql: port = "1433"
sql: login = "radius"
sql: password = "SUPERDUPERSECRET"
sql: radius_db = "radius"
sql: acct_table = "radacct"
sql: acct_table2 = "radacct2"
sql: authcheck_table = "radcheck"
sql: authreply_table = "radreply"
sql: groupcheck_table = "radgroupcheck"
sql: groupreply_table = "radgroupreply"
sql: usergroup_table = "usergroup"
sql: nas_table = "nas"
sql: dict_table = "dictionary"
sql: sqltrace = no
sql: sqltracefile = "/tmp/sqltrace.sql"
sql: readclients = no
sql: deletestalesessions = yes
sql: num_sql_socks = 10
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 radacct2 SET AcctStopTime='%S',
AcctSessionTime=unix_timestamp('%S') - unix_timestamp(AcctStartTime) WHERE
AcctSessionTime=0 AND AcctStopTime=0 AND PropelClientNASIPAddress=
'%{Propel-Client-NAS-IP-Address}' AND AcctStartTime <= '%S'"
sql: accounting_update_query = "UPDATE radacct2 SET PropelClientIPAddress =
'%{Propel-Client-IP-Address}' WHERE AcctSessionId = '%{Acct-Session-Id}' AND
UserName = '%{SQL-User-Name}' AND PropelClientNASIPAddress=
'%{Propel-Client-NAS-IP-Address}' AND AcctStopTime = 0"
sql: accounting_update_query_alt = ""
sql: accounting_start_query = "INSERT into radacct2 (AcctSessionId,
AcctUniqueId, UserName, Realm, NASIPAddress, AcctStartTime, AcctSessionTime,
ClientIPAddress, PropelDialedDigits, PropelClientIPAddress,
PropelClientNASIPAddress, PropelClientSourceID, StrippedUserName,
FreeRadiusProxiedTo) values('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}',
'%{SQL-User-Name}', '%{Realm}', '%{NAS-IP-Address}', getdate(), '',
'%{Client-IP-Address}','%{Propel-Dialed-Digits}',
'%{Propel-Client-IP-Address}', '%{Propel-Client-NAS-IP-Address}',
'%{Propel-Client-Source-ID}', '%{Stripped-User-Name}',
'%{Freeradius-Proxied-To}')"
sql: accounting_start_query_alt = ""
sql: accounting_stop_query = "execute radius.dbo.spRadacct_UPD @AcctSessionId=
'%{Acct-Session-Id}', @UserName = '%{SQL-User-Name}'"
sql: accounting_stop_query_alt = ""
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 = ""
sql: postauth_table = "radpostauth"
sql: postauth_query = ""
sql: safe-characters =
"@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /"
rlm_sql (sql-auth): Driver rlm_sql_unixodbc (module rlm_sql_unixodbc) loaded
and linked
rlm_sql (sql-auth): Attempting to connect to [EMAIL PROTECTED]:1433/radius
rlm_sql (sql-auth): starting 0
[snip repeated 8 times]
rlm_sql (sql-auth): starting 9
rlm_sql (sql-auth): Attempting to connect rlm_sql_unixodbc #9
rlm_sql (sql-auth): Connected new DB handle, #9
Module: Instantiated sql (sql-auth)
Module: Loaded Acct-Unique-Session-Id
acct_unique: key = "User-Name, Acct-Session-Id, Propel-Client-NAS-IP-Address,
Propel-Client-IP-Address, NAS-Port-Id"
Module: Instantiated acct_unique (acct_unique)
Module: Loaded detail
detail: detailfile = "/var/log/radius/radacct/detail-%Y%m%d"
detail: detailperm = 384
detail: dirperm = 493
detail: locking = no
Module: Instantiated detail (detail)
sql: driver = "rlm_sql_unixodbc"
sql: server = "10.1.1.72"
sql: port = "1433"
sql: login = "radius"
sql: password = "SUPERDUPERSECRET"
sql: radius_db = "radius"
sql: acct_table = "radacct"
sql: acct_table2 = "radacct2"
sql: authcheck_table = "radcheck"
sql: authreply_table = "radreply"
sql: groupcheck_table = "radgroupcheck"
sql: groupreply_table = "radgroupreply"
sql: usergroup_table = "usergroup"
sql: nas_table = "nas"
sql: dict_table = "dictionary"
sql: sqltrace = no
sql: sqltracefile = "/tmp/sqltrace.sql"
sql: readclients = no
sql: deletestalesessions = yes
sql: num_sql_socks = 30
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 radacct2 SET AcctStopTime='%S',
AcctSessionTime=unix_timestamp('%S') - unix_timestamp(AcctStartTime) WHERE
AcctSessionTime=0 AND AcctStopTime=0 AND PropelClientNASIPAddress=
'%{Propel-Client-NAS-IP-Address}' AND AcctStartTime <= '%S'"
sql: accounting_update_query = "UPDATE radacct2 SET PropelClientIPAddress =
'%{Propel-Client-IP-Address}' WHERE AcctSessionId = '%{Acct-Session-Id}' AND
UserName = '%{SQL-User-Name}' AND PropelClientNASIPAddress=
'%{Propel-Client-NAS-IP-Address}' AND AcctStopTime = 0"
sql: accounting_update_query_alt = ""
sql: accounting_start_query = "INSERT into radacct2 (AcctSessionId,
AcctUniqueId, UserName, Realm, NASIPAddress, AcctStartTime, AcctSessionTime,
ClientIPAddress, PropelDialedDigits, PropelClientIPAddress,
PropelClientNASIPAddress, PropelClientSourceID, StrippedUserName,
FreeRadiusProxiedTo) values('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}',
'%{SQL-User-Name}', '%{Realm}', '%{NAS-IP-Address}', getdate(), '',
'%{Client-IP-Address}','%{Propel-Dialed-Digits}',
'%{Propel-Client-IP-Address}', '%{Propel-Client-NAS-IP-Address}',
'%{Propel-Client-Source-ID}', '%{Stripped-User-Name}',
'%{Freeradius-Proxied-To}')"
sql: accounting_start_query_alt = ""
sql: accounting_stop_query = "execute radius.dbo.spRadacct_UPD @AcctSessionId=
'%{Acct-Session-Id}', @UserName = '%{SQL-User-Name}'"
sql: accounting_stop_query_alt = ""
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 = ""
sql: postauth_table = "radpostauth"
sql: postauth_query = ""
sql: safe-characters =
"@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /"
rlm_sql (sql-acct): Driver rlm_sql_unixodbc (module rlm_sql_unixodbc) loaded
and linked
rlm_sql (sql-acct): Attempting to connect to [EMAIL PROTECTED]:1433/radius
rlm_sql (sql-acct): starting 0
[snip repeated 29 times]
rlm_sql (sql-acct): starting 29
rlm_sql (sql-acct): Attempting to connect rlm_sql_unixodbc #29
rlm_sql (sql-acct): Connected new DB handle, #29
Module: Instantiated sql (sql-acct)
main: smux_password = "SUPERDUPERSECRET"
main: snmp_write_access = no
SMUX connect try 1
SMUX open oid: 1.3.6.1.4.1.3317.1.3.1
SMUX open progname: radiusd
SMUX open password: SUPERDUPERSECRET
SMUX register oid: 1.3.6.1.2.1.67.1.1.1.1
SMUX register priority: -1
SMUX register operation: 1
SMUX register oid: 1.3.6.1.2.1.67.2.1.1.1
SMUX register priority: -1
SMUX register operation: 1
Listening on authentication *:1812
Listening on accounting *:1813
Listening on proxy *:1814
Ready to process requests.
SMUX read start
SMUX read len: 12
SMUX message received type: 67 rest len: 4
SMUX_RRSP
SMUX_RRSP value: 0 errstat: 0
--- Walking the entire request list ---
Nothing to do. Sleeping until we see a request.
rad_recv: Access-Request packet from host 127.0.0.1:1026, id=241, length=64
User-Name = "[EMAIL PROTECTED]"
User-Password = "test"
NAS-IP-Address = 255.255.255.255
NAS-Port = 0
Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 0
modcall[authorize]: module "preprocess" returns ok for request 0
rlm_realm: Looking up realm "xyz.com" for User-Name = "[EMAIL PROTECTED]"
rlm_realm: Found realm "xyz.com"
rlm_realm: Adding Stripped-User-Name = "test"
rlm_realm: Proxying request from user test to realm xyz.com
rlm_realm: Adding Realm = "xyz.com"
rlm_realm: Preparing to proxy authentication request to realm "xyz.com"
modcall[authorize]: module "suffix" returns updated for request 0
modcall[authorize]: module "files" returns notfound for request 0
radius_xlat: '[EMAIL PROTECTED]'
rlm_sql (sql-auth): sql_set_user escaped user --> '[EMAIL PROTECTED]'
radius_xlat: 'SELECT id,UserName,Attribute,Value,op FROM radcheck WHERE
Username = '[EMAIL PROTECTED]' ORDER BY id'
rlm_sql (sql-auth): Reserving sql socket id: 9
rlm_sql (sql-auth): User [EMAIL PROTECTED] not found in radcheck
radius_xlat: 'SELECT
radgroupcheck.id,radgroupcheck.GroupName,radgroupcheck.Attribute,radgroupcheck.Value,radgroupcheck.op
FROM radgroupcheck,usergroup WHERE usergroup.Username = '[EMAIL PROTECTED]'
AND usergroup.GroupName = radgroupcheck.GroupName ORDER BY radgroupcheck.id'
radius_xlat: 'SELECT
radgroupreply.id,radgroupreply.GroupName,radgroupreply.Attribute,radgroupreply.Value,radgroupreply.op
FROM radgroupreply,usergroup WHERE usergroup.Username = '[EMAIL PROTECTED]'
AND usergroup.GroupName = radgroupreply.GroupName ORDER BY radgroupreply.id'
rlm_sql (sql-auth): User [EMAIL PROTECTED] not found in radgroupcheck
rlm_sql (sql-auth): User not found
rlm_sql (sql-auth): Released sql socket id: 9
modcall[authorize]: module "sql-auth" returns notfound for request 0
modcall: group authorize returns updated for request 0
Sending Access-Request of id 0 to 12.34.164.83:1812
User-Name = "test"
User-Password = "test"
NAS-IP-Address = 255.255.255.255
NAS-Port = 0
Proxy-State = 0x323431
--- Walking the entire request list ---
Waking up in 6 seconds...
rad_recv: Access-Request packet from host 127.0.0.1:1026, id=241, length=64
Ignoring duplicate packet from client localhost:1026 - ID: 241, due to
outstanding proxied request 0.
--- Walking the entire request list ---
Waking up in 3 seconds...
--- Walking the entire request list ---
Re-sending Access-Request of id 0 to 12.34.164.83:1812
User-Name = "test"
User-Password = "\332[\240F\334\214^\217p\314N\3302\373\036N"
NAS-IP-Address = 255.255.255.255
NAS-Port = 0
Client-IP-Address = 127.0.0.1
Stripped-User-Name = "test"
Realm = "xyz.com"
Realm = "xyz.com"
Proxy-State = 0x323431
Waking up in 5 seconds...
rad_recv: Access-Request packet from host 127.0.0.1:1026, id=241, length=64
Ignoring duplicate packet from client localhost:1026 - ID: 241, due to
outstanding proxied request 0.
Waking up in 5 seconds...
rad_recv: Access-Request packet from host 127.0.0.1:1026, id=241, length=64
Ignoring duplicate packet from client localhost:1026 - ID: 241, due to
outstanding proxied request 0.
--- Walking the entire request list ---
Waking up in 2 seconds...
--- Walking the entire request list ---
Rejecting request 0 due to lack of any response from home server localhost:1026
Server rejecting request 0.
Waking up in 5 seconds...
rad_recv: Access-Request packet from host 127.0.0.1:1026, id=241, length=64
Sending Access-Reject of id 241 to 127.0.0.1:1026
--- Walking the entire request list ---
Cleaning up request 0 ID 241 with timestamp 41efcace
Nothing to do. Sleeping until we see a request.
rad_recv: Access-Request packet from host 127.0.0.1:1026, id=245, length=64
User-Name = "[EMAIL PROTECTED]"
User-Password = "test"
NAS-IP-Address = 255.255.255.255
NAS-Port = 0
Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 1
modcall[authorize]: module "preprocess" returns ok for request 1
rlm_realm: Looking up realm "xyz.com" for User-Name = "[EMAIL PROTECTED]"
rlm_realm: Found realm "xyz.com"
rlm_realm: Adding Stripped-User-Name = "test"
rlm_realm: Proxying request from user test to realm xyz.com
rlm_realm: Adding Realm = "xyz.com"
rlm_realm: Preparing to proxy authentication request to realm "xyz.com"
modcall[authorize]: module "suffix" returns updated for request 1
modcall[authorize]: module "files" returns notfound for request 1
radius_xlat: '[EMAIL PROTECTED]'
rlm_sql (sql-auth): sql_set_user escaped user --> '[EMAIL PROTECTED]'
radius_xlat: 'SELECT id,UserName,Attribute,Value,op FROM radcheck WHERE
Username = '[EMAIL PROTECTED]' ORDER BY id'
rlm_sql (sql-auth): Reserving sql socket id: 8
rlm_sql (sql-auth): User [EMAIL PROTECTED] not found in radcheck
radius_xlat: 'SELECT
radgroupcheck.id,radgroupcheck.GroupName,radgroupcheck.Attribute,radgroupcheck.Value,radgroupcheck.op
FROM radgroupcheck,usergroup WHERE usergroup.Username = '[EMAIL PROTECTED]'
AND usergroup.GroupName = radgroupcheck.GroupName ORDER BY radgroupcheck.id'
radius_xlat: 'SELECT
radgroupreply.id,radgroupreply.GroupName,radgroupreply.Attribute,radgroupreply.Value,radgroupreply.op
FROM radgroupreply,usergroup WHERE usergroup.Username = '[EMAIL PROTECTED]'
AND usergroup.GroupName = radgroupreply.GroupName ORDER BY radgroupreply.id'
rlm_sql (sql-auth): User [EMAIL PROTECTED] not found in radgroupcheck
rlm_sql (sql-auth): User not found
rlm_sql (sql-auth): Released sql socket id: 8
modcall[authorize]: module "sql-auth" returns notfound for request 1
modcall: group authorize returns updated for request 1
Sending Access-Request of id 1 to 12.34.164.83:1812
User-Name = "test"
User-Password = "test"
NAS-IP-Address = 255.255.255.255
NAS-Port = 0
Proxy-State = 0x323435
--- Walking the entire request list ---
Waking up in 6 seconds...
rad_recv: Access-Request packet from host 127.0.0.1:1026, id=245, length=64
Ignoring duplicate packet from client localhost:1026 - ID: 245, due to
outstanding proxied request 1.
--- Walking the entire request list ---
Waking up in 3 seconds...
--- Walking the entire request list ---
Re-sending Access-Request of id 1 to 12.34.164.83:1812
User-Name = "test"
User-Password = "\036\254\370\217\237\24576\304PT\\D\343Ka"
NAS-IP-Address = 255.255.255.255
NAS-Port = 0
Client-IP-Address = 127.0.0.1
Stripped-User-Name = "test"
Realm = "xyz.com"
Realm = "xyz.com"
Proxy-State = 0x323435
Waking up in 5 seconds...
rad_recv: Access-Request packet from host 127.0.0.1:1026, id=245, length=64
Ignoring duplicate packet from client localhost:1026 - ID: 245, due to
outstanding proxied request 1.
Waking up in 5 seconds...
rad_recv: Access-Request packet from host 127.0.0.1:1026, id=245, length=64
Ignoring duplicate packet from client localhost:1026 - ID: 245, due to
outstanding proxied request 1.
--- Walking the entire request list ---
Waking up in 2 seconds...
--- Walking the entire request list ---
Rejecting request 1 due to lack of any response from home server localhost:1026
Server rejecting request 1.
Waking up in 5 seconds...
rad_recv: Access-Request packet from host 127.0.0.1:1026, id=245, length=64
Sending Access-Reject of id 245 to 127.0.0.1:1026
--- Walking the entire request list ---
Cleaning up request 1 ID 245 with timestamp 41efcae6
Nothing to do. Sleeping until we see a request.
