Freeradius PSQL not correctly parsing groupcheck/groupreply

20 Aug 2018

      Hello,

I've recently been tasked with configuring a brand new FreeRADIUS server to work with our core routers, using a spare machine for testing purposes until we can replace our entire setup. I'm a Debian man, so I'm using the latest version available in Debian Stable: 

rhouben@urania:/var/log/freeradius$ apt-cache show freeradius
Package: freeradius
Version: 3.0.12+dfsg-5+deb9u1

I've already gotten most of it working, but one thing I discovered is that the routers (Redbacks, as it happens) made /two/ RADIUS calls -- one to establish the circuit, then another to authenticate the connecting user.

The circuit identifies itself with a User-Name formed by 'router-name'.'slot'.'port'.'circuit ID' -- so in the case of the connection coming in on Dot1q circuit 393 of port 1 of the card in the second physical slot, the User-Name attribute is 'rb1-am-spare.2.1.393' -- and the static password of 'Redback'. 

Now since we've got quite a few users, my first instinct was to move as much of the check and reply attributes into radgroupcheck and radgroupreply to avoid having to enter the same data for every user in the list. However, for some reason I can't seem to track down the system doesn't actually add the attributes from those tables even though it claims to see them.

Below is the full radiusd -X output of a conversation:

root@urania:~# freeradius -X  | ccze -A
FreeRADIUS Version 3.0.12 
Copyright (C) 1999-2016 The FreeRADIUS server project and contributors 
There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A 
PARTICULAR PURPOSE 
You may redistribute copies of FreeRADIUS under the terms of the 
GNU General Public License 
For more information about these matters, see the file named COPYRIGHT 
Starting - reading configuration files ... 
including dictionary file /usr/share/freeradius/dictionary 
including dictionary file /usr/share/freeradius/dictionary.dhcp 
including dictionary file /usr/share/freeradius/dictionary.vqp 
including dictionary file /etc/freeradius/3.0/dictionary 
including configuration file /etc/freeradius/3.0/radiusd.conf 
including configuration file /etc/freeradius/3.0/proxy.conf 
including configuration file /etc/freeradius/3.0/clients.conf 
including files in directory /etc/freeradius/3.0/mods-enabled/ 
including configuration file /etc/freeradius/3.0/mods-enabled/sql 
including configuration file /etc/freeradius/3.0/mods-config/sql/main/sqlite/queries.conf 
including configuration file /etc/freeradius/3.0/mods-enabled/sradutmp 
including configuration file /etc/freeradius/3.0/mods-enabled/dynamic_clients 
including configuration file /etc/freeradius/3.0/mods-enabled/utf8 
including configuration file /etc/freeradius/3.0/mods-enabled/digest 
including configuration file /etc/freeradius/3.0/mods-enabled/echo 
including configuration file /etc/freeradius/3.0/mods-enabled/linelog 
including configuration file /etc/freeradius/3.0/mods-enabled/chap 
including configuration file /etc/freeradius/3.0/mods-enabled/soh 
including configuration file /etc/freeradius/3.0/mods-enabled/detail 
including configuration file /etc/freeradius/3.0/mods-enabled/logintime 
including configuration file /etc/freeradius/3.0/mods-enabled/sql_redbacks_full 
including configuration file /etc/freeradius/3.0/mods-config/sql/main/postgresql/queries.conf 
including configuration file /etc/freeradius/3.0/mods-enabled/sql_redbacks 
including configuration file /etc/freeradius/3.0/mods-enabled/always 
including configuration file /etc/freeradius/3.0/mods-enabled/expr 
including configuration file /etc/freeradius/3.0/mods-enabled/preprocess 
including configuration file /etc/freeradius/3.0/mods-enabled/passwd 
including configuration file /etc/freeradius/3.0/mods-enabled/pap 
including configuration file /etc/freeradius/3.0/mods-enabled/detail.log 
including configuration file /etc/freeradius/3.0/mods-enabled/ntlm_auth 
including configuration file /etc/freeradius/3.0/mods-enabled/mschap 
including configuration file /etc/freeradius/3.0/mods-enabled/exec 
including configuration file /etc/freeradius/3.0/mods-enabled/files 
including configuration file /etc/freeradius/3.0/mods-enabled/eap 
including configuration file /etc/freeradius/3.0/mods-enabled/cache_eap 
including configuration file /etc/freeradius/3.0/mods-enabled/unpack 
including configuration file /etc/freeradius/3.0/mods-enabled/unix 
including configuration file /etc/freeradius/3.0/mods-enabled/replicate 
including configuration file /etc/freeradius/3.0/mods-enabled/attr_filter 
including configuration file /etc/freeradius/3.0/mods-enabled/radutmp 
including configuration file /etc/freeradius/3.0/mods-enabled/realm 
including configuration file /etc/freeradius/3.0/mods-enabled/expiration 
including files in directory /etc/freeradius/3.0/policy.d/ 
including configuration file /etc/freeradius/3.0/policy.d/cui 
including configuration file /etc/freeradius/3.0/policy.d/accounting 
including configuration file /etc/freeradius/3.0/policy.d/debug 
including configuration file /etc/freeradius/3.0/policy.d/operator-name 
including configuration file /etc/freeradius/3.0/policy.d/dhcp 
including configuration file /etc/freeradius/3.0/policy.d/filter 
including configuration file /etc/freeradius/3.0/policy.d/moonshot-targeted-ids 
including configuration file /etc/freeradius/3.0/policy.d/canonicalization 
including configuration file /etc/freeradius/3.0/policy.d/abfab-tr 
including configuration file /etc/freeradius/3.0/policy.d/eap 
including configuration file /etc/freeradius/3.0/policy.d/control 
including files in directory /etc/freeradius/3.0/sites-enabled/ 
including configuration file /etc/freeradius/3.0/sites-enabled/radius-test 
main { 
 security { 
 	user = "freerad" 
 	group = "freerad" 
 	allow_core_dumps = no 
 } 
	name = "freeradius" 
	prefix = "/usr" 
	localstatedir = "/var" 
	logdir = "/var/log/freeradius" 
	run_dir = "/var/run/freeradius" 
} 
main { 
	name = "freeradius" 
	prefix = "/usr" 
	localstatedir = "/var" 
	sbindir = "/usr/sbin" 
	logdir = "/var/log/freeradius" 
	run_dir = "/var/run/freeradius" 
	libdir = "/usr/lib/freeradius" 
	radacctdir = "/var/log/freeradius/radacct" 
	hostname_lookups = no 
	max_request_time = 30 
	cleanup_delay = 5 
	max_requests = 16384 
	pidfile = "/var/run/freeradius/freeradius.pid" 
	checkrad = "/usr/sbin/checkrad" 
	debug_level = 0 
	proxy_requests = yes 
 log { 
 	stripped_names = no 
 	auth = no 
 	auth_badpass = no 
 	auth_goodpass = no 
 	colourise = yes 
 	msg_denied = "You are already logged in - access denied" 
 } 
 resources { 
 } 
 security { 
 	max_attributes = 200 
 	reject_delay = 1.000000 
 	status_server = yes 
 } 
} 
radiusd: #### Loading Realms and Home Servers #### 
 proxy server { 
 	retry_delay = 5 
 	retry_count = 3 
 	default_fallback = no 
 	dead_time = 120 
 	wake_all_if_all_dead = no 
 } 
 home_server localhost { 
 	ipaddr = 127.0.0.1 
 	port = 1812 
 	type = "auth" 
 	secret = <<< secret >>> 
 	response_window = 20.000000 
 	response_timeouts = 1 
 	max_outstanding = 65536 
 	zombie_period = 40 
 	status_check = "status-server" 
 	ping_interval = 30 
 	check_interval = 30 
 	check_timeout = 4 
 	num_answers_to_alive = 3 
 	revive_interval = 120 
  limit { 
  	max_connections = 16 
  	max_requests = 0 
  	lifetime = 0 
  	idle_timeout = 0 
  } 
  coa { 
  	irt = 2 
  	mrt = 16 
  	mrc = 5 
  	mrd = 30 
  } 
 } 
 home_server_pool my_auth_failover { 
	type = fail-over 
	home_server = localhost 
 } 
 realm example.com { 
	auth_pool = my_auth_failover 
 } 
 realm LOCAL { 
 } 
radiusd: #### Loading Clients #### 
 client localhost { 
 	ipaddr = 127.0.0.1 
 	require_message_authenticator = no 
 	secret = <<< secret >>> 
 	nas_type = "other" 
 	proto = "*" 
  limit { 
  	max_connections = 16 
  	lifetime = 0 
  	idle_timeout = 30 
  } 
 } 
 client localhost_ipv6 { 
 	ipv6addr = ::1 
 	require_message_authenticator = no 
 	secret = <<< secret >>> 
  limit { 
  	max_connections = 16 
  	lifetime = 0 
  	idle_timeout = 30 
  } 
 } 
 client redback-test.systemec.office { 
 	ipaddr = 192.168.10.10 
 	require_message_authenticator = no 
 	secret = <<< secret >>> 
 	shortname = "redback-test" 
 	virtual_server = "radius-test" 
  limit { 
  	max_connections = 16 
  	lifetime = 0 
  	idle_timeout = 30 
  } 
 } 
Debugger not attached 
 # Creating Auth-Type = eap 
 # Creating Auth-Type = pap 
 # Creating Auth-Type = mschap 
 # Creating Auth-Type = MS-CHAP 
 # Creating Post-Auth-Type = Accept 
radiusd: #### Instantiating modules #### 
 modules { 
  # Loaded module rlm_sql 
  # Loading module "sql" from file /etc/freeradius/3.0/mods-enabled/sql 
  sql { 
  	driver = "rlm_sql_null" 
  	server = "" 
  	port = 0 
  	login = "" 
  	password = <<< secret >>> 
  	radius_db = "radius" 
  	read_groups = yes 
  	read_profiles = yes 
  	read_clients = no 
  	delete_stale_sessions = yes 
  	sql_user_name = "%{User-Name}" 
  	default_user_profile = "" 
  	client_query = "SELECT id, nasname, shortname, type, secret, server FROM nas" 
  	authorize_check_query = "SELECT id, username, attribute, value, op FROM radcheck WHERE username = '%{SQL-User-Name}' ORDER BY id" 
  	authorize_reply_query = "SELECT id, username, attribute, value, op FROM radreply WHERE username = '%{SQL-User-Name}' ORDER BY id" 
  	authorize_group_check_query = "SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = '%{SQL-Group}' ORDER BY id" 
  	authorize_group_reply_query = "SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = '%{SQL-Group}' ORDER BY id" 
  	group_membership_query = "SELECT groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority" 
  	simul_count_query = "SELECT COUNT(*) FROM radacct WHERE username = '%{SQL-User-Name}' AND acctstoptime IS NULL" 
  	simul_verify_query = "SELECT radacctid, acctsessionid, username, nasipaddress, nasportid, framedipaddress, callingstationid, framedprotocol FROM radacct WHERE username = '%{SQL-Group}' AND acctstoptime IS NULL" 
  	safe_characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /" 
   accounting { 
   	reference = "%{tolower:type.%{Acct-Status-Type}.query}" 
    type { 
     accounting-on { 
     	query = "UPDATE radacct SET acctstoptime = %{%{integer:Event-Timestamp}:-date('now')}, acctsessiontime	= (%{%{integer:Event-Timestamp}:-strftime('%%s', 'now')} - strftime('%%s', acctstarttime)), acctterminatecause = '%{Acct-Terminate-Cause}' WHERE acctstoptime IS NULL AND nasipaddress   = '%{NAS-IP-Address}' AND acctstarttime <= %{integer:Event-Timestamp}" 
     } 
     accounting-off { 
     	query = "UPDATE radacct SET acctstoptime = %{%{integer:Event-Timestamp}:-date('now')}, acctsessiontime	= (%{%{integer:Event-Timestamp}:-strftime('%%s', 'now')} - strftime('%%s', acctstarttime)), acctterminatecause = '%{Acct-Terminate-Cause}' WHERE acctstoptime IS NULL AND nasipaddress   = '%{NAS-IP-Address}' AND acctstarttime <= %{integer:Event-Timestamp}" 
     } 
     start { 
     	query = "INSERT INTO radacct (acctsessionid, acctuniqueid, username, realm, nasipaddress, nasportid, nasporttype, acctstarttime, acctupdatetime, acctstoptime, acctsessiontime, acctauthentic, connectinfo_start, connectinfo_stop, acctinputoctets, acctoutputoctets, calledstationid, callingstationid, acctterminatecause, servicetype, framedprotocol, framedipaddress) VALUES ('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}', '%{SQL-User-Name}', '%{Realm}', '%{NAS-IP-Address}', '%{%{NAS-Port-ID}:-%{NAS-Port}}', '%{NAS-Port-Type}', %{%{integer:Event-Timestamp}:-date('now')}, %{%{integer:Event-Timestamp}:-date('now')}, NULL, '0', '%{Acct-Authentic}', '%{Connect-Info}', '', '0', '0', '%{Called-Station-Id}', '%{Calling-Station-Id}', '', '%{Service-Type}', '%{Framed-Protocol}', '%{Framed-IP-Address}')" 
     } 
     interim-update { 
     	query = "UPDATE radacct SET acctupdatetime  = %{%{integer:Event-Timestamp}:-date('now')}, acctinterval    = 0, framedipaddress = '%{Framed-IP-Address}', acctsessiontime = %{%{Acct-Session-Time}:-NULL}, acctinputoctets = %{%{Acct-Input-Gigawords}:-0} << 32 | %{%{Acct-Input-Octets}:-0}, acctoutputoctets = %{%{Acct-Output-Gigawords}:-0} << 32 | %{%{Acct-Output-Octets}:-0} WHERE AcctUniqueId = '%{Acct-Unique-Session-Id}'" 
     } 
     stop { 
     	query = "UPDATE radacct SET acctstoptime	= %{%{integer:Event-Timestamp}:-date('now')}, acctsessiontime	= %{%{Acct-Session-Time}:-NULL}, acctinputoctets	= %{%{Acct-Input-Gigawords}:-0} << 32 | %{%{Acct-Input-Octets}:-0}, acctoutputoctets = %{%{Acct-Output-Gigawords}:-0} << 32 | %{%{Acct-Output-Octets}:-0}, acctterminatecause = '%{Acct-Terminate-Cause}', connectinfo_stop = '%{Connect-Info}' WHERE AcctUniqueId = '%{Acct-Unique-Session-Id}'" 
     } 
    } 
   } 
   post-auth { 
   	reference = ".query" 
   	query = "INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '%{SQL-User-Name}', '%{%{User-Password}:-%{Chap-Password}}', '%{reply:Packet-Type}', '%S')" 
   } 
  } 
rlm_sql (sql): Driver rlm_sql_null (module rlm_sql_null) loaded and linked 
Creating attribute SQL-Group 
  # Loaded module rlm_radutmp 
  # Loading module "sradutmp" from file /etc/freeradius/3.0/mods-enabled/sradutmp 
  radutmp sradutmp { 
  	filename = "/var/log/freeradius/sradutmp" 
  	username = "%{User-Name}" 
  	case_sensitive = yes 
  	check_with_nas = yes 
  	permissions = 420 
  	caller_id = no 
  } 
  # Loaded module rlm_dynamic_clients 
  # Loading module "dynamic_clients" from file /etc/freeradius/3.0/mods-enabled/dynamic_clients 
  # Loaded module rlm_utf8 
  # Loading module "utf8" from file /etc/freeradius/3.0/mods-enabled/utf8 
  # Loaded module rlm_digest 
  # Loading module "digest" from file /etc/freeradius/3.0/mods-enabled/digest 
  # Loaded module rlm_exec 
  # Loading module "echo" from file /etc/freeradius/3.0/mods-enabled/echo 
  exec echo { 
  	wait = yes 
  	program = "/bin/echo %{User-Name}" 
  	input_pairs = "request" 
  	output_pairs = "reply" 
  	shell_escape = yes 
  } 
  # Loaded module rlm_linelog 
  # Loading module "linelog" from file /etc/freeradius/3.0/mods-enabled/linelog 
  linelog { 
  	filename = "/var/log/freeradius/linelog" 
  	escape_filenames = no 
  	syslog_severity = "info" 
  	permissions = 384 
  	format = "This is a log message for %{User-Name}" 
  	reference = "messages.%{%{reply:Packet-Type}:-default}" 
  } 
  # Loading module "log_accounting" from file /etc/freeradius/3.0/mods-enabled/linelog 
  linelog log_accounting { 
  	filename = "/var/log/freeradius/linelog-accounting" 
  	escape_filenames = no 
  	syslog_severity = "info" 
  	permissions = 384 
  	format = "" 
  	reference = "Accounting-Request.%{%{Acct-Status-Type}:-unknown}" 
  } 
  # Loaded module rlm_chap 
  # Loading module "chap" from file /etc/freeradius/3.0/mods-enabled/chap 
  # Loaded module rlm_soh 
  # Loading module "soh" from file /etc/freeradius/3.0/mods-enabled/soh 
  soh { 
  	dhcp = yes 
  } 
  # Loaded module rlm_detail 
  # Loading module "detail" from file /etc/freeradius/3.0/mods-enabled/detail 
  detail { 
  	filename = "/var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d" 
  	header = "%t" 
  	permissions = 384 
  	locking = no 
  	escape_filenames = no 
  	log_packet_header = no 
  } 
  # Loaded module rlm_logintime 
  # Loading module "logintime" from file /etc/freeradius/3.0/mods-enabled/logintime 
  logintime { 
  	minimum_timeout = 60 
  } 
  # Loading module "sql_psql_redbacks_full" from file /etc/freeradius/3.0/mods-enabled/sql_redbacks_full 
  sql sql_psql_redbacks_full { 
  	driver = "rlm_sql_postgresql" 
  	server = "" 
  	port = 5432 
  	login = "freerad" 
  	password = <<< secret >>> 
  	radius_db = "radius" 
  	read_groups = yes 
  	read_profiles = yes 
  	read_clients = no 
  	delete_stale_sessions = yes 
  	sql_user_name = "%{User-Name}" 
  	default_user_profile = "" 
  	client_query = "SELECT id, nasname, shortname, type, secret, server FROM nas" 
  	authorize_check_query = "SELECT id, UserName, Attribute, Value, Op FROM radcheck WHERE Username = '%{SQL-User-Name}' ORDER BY id" 
  	authorize_reply_query = "SELECT id, UserName, Attribute, Value, Op FROM radreply WHERE Username = '%{SQL-User-Name}' ORDER BY id" 
  	authorize_group_check_query = "SELECT id, GroupName, Attribute, Value, op FROM radgroupcheck WHERE GroupName = '%{SQL-Group}' ORDER BY id" 
  	authorize_group_reply_query = "SELECT id, GroupName, Attribute, Value, op FROM radgroupreply WHERE GroupName = '%{SQL-Group}' ORDER BY id" 
  	group_membership_query = "SELECT GroupName FROM radusergroup WHERE UserName='%{SQL-User-Name}' ORDER BY priority" 
  	simul_count_query = "SELECT COUNT(*) FROM radacct WHERE UserName='%{SQL-User-Name}' AND AcctStopTime IS NULL" 
  	simul_verify_query = "SELECT RadAcctId, AcctSessionId, UserName, NASIPAddress, NASPortId, FramedIPAddress, CallingStationId, FramedProtocol FROM radacct WHERE UserName='%{SQL-User-Name}' AND AcctStopTime IS NULL" 
  	safe_characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /" 
  	query_timeout = 60 
   accounting { 
   	reference = "%{tolower:type.%{%{Acct-Status-Type}:-none}.query}" 
    type { 
     accounting-on { 
     	query = "UPDATE radacct SET AcctStopTime = TO_TIMESTAMP(%{integer:Event-Timestamp}), AcctUpdateTime = TO_TIMESTAMP(%{integer:Event-Timestamp}), AcctSessionTime = (%{integer:Event-Timestamp} - EXTRACT(EPOCH FROM(AcctStartTime))), AcctTerminateCause = '%{%{Acct-Terminate-Cause}:-NAS-Reboot}' WHERE AcctStopTime IS NULL AND NASIPAddress= '%{%{NAS-IPv6-Address}:-%{NAS-IP-Address}}' AND AcctStartTime <= '%S'::timestamp" 
     } 
     accounting-off { 
     	query = "UPDATE radacct SET AcctStopTime = TO_TIMESTAMP(%{integer:Event-Timestamp}), AcctUpdateTime = TO_TIMESTAMP(%{integer:Event-Timestamp}), AcctSessionTime = (%{integer:Event-Timestamp} - EXTRACT(EPOCH FROM(AcctStartTime))), AcctTerminateCause = '%{%{Acct-Terminate-Cause}:-NAS-Reboot}' WHERE AcctStopTime IS NULL AND NASIPAddress= '%{%{NAS-IPv6-Address}:-%{NAS-IP-Address}}' AND AcctStartTime <= '%S'::timestamp" 
     } 
     start { 
     	query = "INSERT INTO radacct (AcctSessionId, AcctUniqueId, UserName, Realm, NASIPAddress, NASPortId, NASPortType, AcctStartTime, AcctUpdateTime, AcctStopTime, AcctSessionTime, AcctAuthentic, ConnectInfo_start, ConnectInfo_Stop, AcctInputOctets, AcctOutputOctets, CalledStationId, CallingStationId, AcctTerminateCause, ServiceType, FramedProtocol, FramedIpAddress) VALUES('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}', '%{SQL-User-Name}', NULLIF('%{Realm}', ''), '%{%{NAS-IPv6-Address}:-%{NAS-IP-Address}}', NULLIF('%{%{NAS-Port-ID}:-%{NAS-Port}}', ''), '%{NAS-Port-Type}', TO_TIMESTAMP(%{integer:Event-Timestamp}), TO_TIMESTAMP(%{integer:Event-Timestamp}), NULL, 0, '%{Acct-Authentic}', '%{Connect-Info}', NULL, 0, 0, '%{Called-Station-Id}', '%{Calling-Station-Id}', NULL, '%{Service-Type}', '%{Framed-Protocol}', NULLIF('%{Framed-IP-Address}', '')::inet)" 
     } 
     interim-update { 
     	query = "UPDATE radacct SET FramedIPAddress = NULLIF('%{Framed-IP-Address}', '')::inet, AcctSessionTime = %{%{Acct-Session-Time}:-NULL}, AcctInterval = (%{integer:Event-Timestamp} - EXTRACT(EPOCH FROM (COALESCE(AcctUpdateTime, AcctStartTime)))), AcctUpdateTime = TO_TIMESTAMP(%{integer:Event-Timestamp}), AcctInputOctets = (('%{%{Acct-Input-Gigawords}:-0}'::bigint << 32) + '%{%{Acct-Input-Octets}:-0}'::bigint), AcctOutputOctets = (('%{%{Acct-Output-Gigawords}:-0}'::bigint << 32) + '%{%{Acct-Output-Octets}:-0}'::bigint) WHERE AcctUniqueId = '%{Acct-Unique-Session-Id}' AND AcctStopTime IS NULL" 
     } 
     stop { 
     	query = "UPDATE radacct SET AcctStopTime = TO_TIMESTAMP(%{integer:Event-Timestamp}), AcctUpdateTime = TO_TIMESTAMP(%{integer:Event-Timestamp}), AcctSessionTime = COALESCE(%{%{Acct-Session-Time}:-NULL}, (%{integer:Event-Timestamp} - EXTRACT(EPOCH FROM(AcctStartTime)))), AcctInputOctets = (('%{%{Acct-Input-Gigawords}:-0}'::bigint << 32) + '%{%{Acct-Input-Octets}:-0}'::bigint), AcctOutputOctets = (('%{%{Acct-Output-Gigawords}:-0}'::bigint << 32) + '%{%{Acct-Output-Octets}:-0}'::bigint), AcctTerminateCause = '%{Acct-Terminate-Cause}', FramedIPAddress = NULLIF('%{Framed-IP-Address}', '')::inet, ConnectInfo_stop = '%{Connect-Info}' WHERE AcctUniqueId = '%{Acct-Unique-Session-Id}' AND AcctStopTime IS NULL" 
     } 
    } 
   } 
   post-auth { 
   	reference = ".query" 
   	query = "INSERT INTO radpostauth (username, pass, reply, authdate) VALUES('%{User-Name}', '%{%{User-Password}:-Chap-Password}', '%{reply:Packet-Type}', NOW())" 
   } 
  } 
rlm_sql (sql_psql_redbacks_full): Driver rlm_sql_postgresql (module rlm_sql_postgresql) loaded and linked 
Creating attribute sql_psql_redbacks_full-SQL-Group 
  # Loading module "sql_psql_redbacks" from file /etc/freeradius/3.0/mods-enabled/sql_redbacks 
  sql sql_psql_redbacks { 
  	driver = "rlm_sql_postgresql" 
  	server = "localhost" 
  	port = 5432 
  	login = "freerad" 
  	password = <<< secret >>> 
  	radius_db = "radius" 
  	read_groups = yes 
  	read_profiles = yes 
  	read_clients = no 
  	delete_stale_sessions = yes 
  	sql_user_name = "" 
  	default_user_profile = "" 
  	client_query = "SELECT id,nasname,shortname,type,secret FROM nas" 
  	safe_characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /" 
   accounting { 
   	reference = ".query" 
    type { 
     accounting-on { 
     } 
     accounting-off { 
     } 
     start { 
     } 
     interim-update { 
     } 
     stop { 
     } 
    } 
   } 
   post-auth { 
   	reference = ".query" 
   } 
  } 
rlm_sql (sql_psql_redbacks): Driver rlm_sql_postgresql (module rlm_sql_postgresql) loaded and linked 
  # Loaded module rlm_always 
  # Loading module "reject" from file /etc/freeradius/3.0/mods-enabled/always 
  always reject { 
  	rcode = "reject" 
  	simulcount = 0 
  	mpp = no 
  } 
  # Loading module "fail" from file /etc/freeradius/3.0/mods-enabled/always 
  always fail { 
  	rcode = "fail" 
  	simulcount = 0 
  	mpp = no 
  } 
  # Loading module "ok" from file /etc/freeradius/3.0/mods-enabled/always 
  always ok { 
  	rcode = "ok" 
  	simulcount = 0 
  	mpp = no 
  } 
  # Loading module "handled" from file /etc/freeradius/3.0/mods-enabled/always 
  always handled { 
  	rcode = "handled" 
  	simulcount = 0 
  	mpp = no 
  } 
  # Loading module "invalid" from file /etc/freeradius/3.0/mods-enabled/always 
  always invalid { 
  	rcode = "invalid" 
  	simulcount = 0 
  	mpp = no 
  } 
  # Loading module "userlock" from file /etc/freeradius/3.0/mods-enabled/always 
  always userlock { 
  	rcode = "userlock" 
  	simulcount = 0 
  	mpp = no 
  } 
  # Loading module "notfound" from file /etc/freeradius/3.0/mods-enabled/always 
  always notfound { 
  	rcode = "notfound" 
  	simulcount = 0 
  	mpp = no 
  } 
  # Loading module "noop" from file /etc/freeradius/3.0/mods-enabled/always 
  always noop { 
  	rcode = "noop" 
  	simulcount = 0 
  	mpp = no 
  } 
  # Loading module "updated" from file /etc/freeradius/3.0/mods-enabled/always 
  always updated { 
  	rcode = "updated" 
  	simulcount = 0 
  	mpp = no 
  } 
  # Loaded module rlm_expr 
  # Loading module "expr" from file /etc/freeradius/3.0/mods-enabled/expr 
  expr { 
  	safe_characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /äéöüàâæçèéêëîïôoùûüaÿÄÉÖÜßÀÂÆÇÈÉÊËÎÏÔOÙÛÜY" 
  } 
  # Loaded module rlm_preprocess 
  # Loading module "preprocess" from file /etc/freeradius/3.0/mods-enabled/preprocess 
  preprocess { 
  	huntgroups = "/etc/freeradius/3.0/mods-config/preprocess/huntgroups" 
  	hints = "/etc/freeradius/3.0/mods-config/preprocess/hints" 
  	with_ascend_hack = no 
  	ascend_channels_per_line = 23 
  	with_ntdomain_hack = no 
  	with_specialix_jetstream_hack = no 
  	with_cisco_vsa_hack = no 
  	with_alvarion_vsa_hack = no 
  } 
  # Loaded module rlm_passwd 
  # Loading module "etc_passwd" from file /etc/freeradius/3.0/mods-enabled/passwd 
  passwd etc_passwd { 
  	filename = "/etc/passwd" 
  	format = "*User-Name:Crypt-Password:" 
  	delimiter = ":" 
  	ignore_nislike = no 
  	ignore_empty = yes 
  	allow_multiple_keys = no 
  	hash_size = 100 
  } 
  # Loaded module rlm_pap 
  # Loading module "pap" from file /etc/freeradius/3.0/mods-enabled/pap 
  pap { 
  	normalise = yes 
  } 
  # Loading module "auth_log" from file /etc/freeradius/3.0/mods-enabled/detail.log 
  detail auth_log { 
  	filename = "/var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d" 
  	header = "%t" 
  	permissions = 384 
  	locking = no 
  	escape_filenames = no 
  	log_packet_header = no 
  } 
  # Loading module "reply_log" from file /etc/freeradius/3.0/mods-enabled/detail.log 
  detail reply_log { 
  	filename = "/var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/reply-detail-%Y%m%d" 
  	header = "%t" 
  	permissions = 384 
  	locking = no 
  	escape_filenames = no 
  	log_packet_header = no 
  } 
  # Loading module "pre_proxy_log" from file /etc/freeradius/3.0/mods-enabled/detail.log 
  detail pre_proxy_log { 
  	filename = "/var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/pre-proxy-detail-%Y%m%d" 
  	header = "%t" 
  	permissions = 384 
  	locking = no 
  	escape_filenames = no 
  	log_packet_header = no 
  } 
  # Loading module "post_proxy_log" from file /etc/freeradius/3.0/mods-enabled/detail.log 
  detail post_proxy_log { 
  	filename = "/var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/post-proxy-detail-%Y%m%d" 
  	header = "%t" 
  	permissions = 384 
  	locking = no 
  	escape_filenames = no 
  	log_packet_header = no 
  } 
  # Loading module "ntlm_auth" from file /etc/freeradius/3.0/mods-enabled/ntlm_auth 
  exec ntlm_auth { 
  	wait = yes 
  	program = "/path/to/ntlm_auth --request-nt-key --domain=MYDOMAIN --username=%{mschap:User-Name} --password=%{User-Password}" 
  	shell_escape = yes 
  } 
  # Loaded module rlm_mschap 
  # Loading module "mschap" from file /etc/freeradius/3.0/mods-enabled/mschap 
  mschap { 
  	use_mppe = yes 
  	require_encryption = no 
  	require_strong = no 
  	with_ntdomain_hack = yes 
   passchange { 
   } 
  	allow_retry = yes 
  } 
  # Loading module "exec" from file /etc/freeradius/3.0/mods-enabled/exec 
  exec { 
  	wait = no 
  	input_pairs = "request" 
  	shell_escape = yes 
  	timeout = 10 
  } 
  # Loaded module rlm_files 
  # Loading module "files" from file /etc/freeradius/3.0/mods-enabled/files 
  files { 
  	filename = "/etc/freeradius/3.0/mods-config/files/authorize" 
  	acctusersfile = "/etc/freeradius/3.0/mods-config/files/accounting" 
  	preproxy_usersfile = "/etc/freeradius/3.0/mods-config/files/pre-proxy" 
  } 
  # Loaded module rlm_eap 
  # Loading module "eap" from file /etc/freeradius/3.0/mods-enabled/eap 
  eap { 
  	default_eap_type = "md5" 
  	timer_expire = 60 
  	ignore_unknown_eap_types = no 
  	cisco_accounting_username_bug = no 
  	max_sessions = 16384 
  } 
  # Loaded module rlm_cache 
  # Loading module "cache_eap" from file /etc/freeradius/3.0/mods-enabled/cache_eap 
  cache cache_eap { 
  	driver = "rlm_cache_rbtree" 
  	key = "%{%{control:State}:-%{%{reply:State}:-%{State}}}" 
  	ttl = 15 
  	max_entries = 0 
  	epoch = 0 
  	add_stats = no 
  } 
  # Loaded module rlm_unpack 
  # Loading module "unpack" from file /etc/freeradius/3.0/mods-enabled/unpack 
  # Loaded module rlm_unix 
  # Loading module "unix" from file /etc/freeradius/3.0/mods-enabled/unix 
  unix { 
  	radwtmp = "/var/log/freeradius/radwtmp" 
  } 
Creating attribute Unix-Group 
  # Loaded module rlm_replicate 
  # Loading module "replicate" from file /etc/freeradius/3.0/mods-enabled/replicate 
  # Loaded module rlm_attr_filter 
  # Loading module "attr_filter.post-proxy" from file /etc/freeradius/3.0/mods-enabled/attr_filter 
  attr_filter attr_filter.post-proxy { 
  	filename = "/etc/freeradius/3.0/mods-config/attr_filter/post-proxy" 
  	key = "%{Realm}" 
  	relaxed = no 
  } 
  # Loading module "attr_filter.pre-proxy" from file /etc/freeradius/3.0/mods-enabled/attr_filter 
  attr_filter attr_filter.pre-proxy { 
  	filename = "/etc/freeradius/3.0/mods-config/attr_filter/pre-proxy" 
  	key = "%{Realm}" 
  	relaxed = no 
  } 
  # Loading module "attr_filter.access_reject" from file /etc/freeradius/3.0/mods-enabled/attr_filter 
  attr_filter attr_filter.access_reject { 
  	filename = "/etc/freeradius/3.0/mods-config/attr_filter/access_reject" 
  	key = "%{User-Name}" 
  	relaxed = no 
  } 
  # Loading module "attr_filter.access_challenge" from file /etc/freeradius/3.0/mods-enabled/attr_filter 
  attr_filter attr_filter.access_challenge { 
  	filename = "/etc/freeradius/3.0/mods-config/attr_filter/access_challenge" 
  	key = "%{User-Name}" 
  	relaxed = no 
  } 
  # Loading module "attr_filter.accounting_response" from file /etc/freeradius/3.0/mods-enabled/attr_filter 
  attr_filter attr_filter.accounting_response { 
  	filename = "/etc/freeradius/3.0/mods-config/attr_filter/accounting_response" 
  	key = "%{User-Name}" 
  	relaxed = no 
  } 
  # Loading module "radutmp" from file /etc/freeradius/3.0/mods-enabled/radutmp 
  radutmp { 
  	filename = "/var/log/freeradius/radutmp" 
  	username = "%{User-Name}" 
  	case_sensitive = yes 
  	check_with_nas = yes 
  	permissions = 384 
  	caller_id = yes 
  } 
  # Loaded module rlm_realm 
  # Loading module "IPASS" from file /etc/freeradius/3.0/mods-enabled/realm 
  realm IPASS { 
  	format = "prefix" 
  	delimiter = "/" 
  	ignore_default = no 
  	ignore_null = no 
  } 
  # Loading module "suffix" from file /etc/freeradius/3.0/mods-enabled/realm 
  realm suffix { 
  	format = "suffix" 
  	delimiter = "@" 
  	ignore_default = no 
  	ignore_null = no 
  } 
  # Loading module "realmpercent" from file /etc/freeradius/3.0/mods-enabled/realm 
  realm realmpercent { 
  	format = "suffix" 
  	delimiter = "%" 
  	ignore_default = no 
  	ignore_null = no 
  } 
  # Loading module "ntdomain" from file /etc/freeradius/3.0/mods-enabled/realm 
  realm ntdomain { 
  	format = "prefix" 
  	delimiter = "\\" 
  	ignore_default = no 
  	ignore_null = no 
  } 
  # Loaded module rlm_expiration 
  # Loading module "expiration" from file /etc/freeradius/3.0/mods-enabled/expiration 
  instantiate { 
  } 
  # Instantiating module "sql" from file /etc/freeradius/3.0/mods-enabled/sql 
rlm_sql (sql): Attempting to connect to database "radius" 
rlm_sql (sql): Initialising connection pool 
   pool { 
   	start = 5 
   	min = 3 
   	max = 32 
   	spare = 10 
   	uses = 0 
   	lifetime = 0 
   	cleanup_interval = 30 
   	idle_timeout = 60 
   	retry_delay = 30 
   	spread = no 
   } 
rlm_sql (sql): Opening additional connection (0), 1 of 32 pending slots used 
rlm_sql (sql): Opening additional connection (1), 1 of 31 pending slots used 
rlm_sql (sql): Opening additional connection (2), 1 of 30 pending slots used 
rlm_sql (sql): Opening additional connection (3), 1 of 29 pending slots used 
rlm_sql (sql): Opening additional connection (4), 1 of 28 pending slots used 
  # Instantiating module "linelog" from file /etc/freeradius/3.0/mods-enabled/linelog 
  # Instantiating module "log_accounting" from file /etc/freeradius/3.0/mods-enabled/linelog 
  # Instantiating module "detail" from file /etc/freeradius/3.0/mods-enabled/detail 
  # Instantiating module "logintime" from file /etc/freeradius/3.0/mods-enabled/logintime 
  # Instantiating module "sql_psql_redbacks_full" from file /etc/freeradius/3.0/mods-enabled/sql_redbacks_full 
   postgresql { 
   	send_application_name = yes 
   } 
rlm_sql (sql_psql_redbacks_full): Attempting to connect to database "radius" 
rlm_sql (sql_psql_redbacks_full): Initialising connection pool 
   pool { 
   	start = 5 
   	min = 3 
   	max = 32 
   	spare = 10 
   	uses = 5 
   	lifetime = 0 
   	cleanup_interval = 30 
   	idle_timeout = 90 
   	retry_delay = 30 
   	spread = no 
   } 
rlm_sql (sql_psql_redbacks_full): Opening additional connection (0), 1 of 32 pending slots used 
Connected to database 'radius' on '/var/run/postgresql' server version 90513, protocol version 3, backend PID 30168  
  # Instantiating module "sql_psql_redbacks" from file /etc/freeradius/3.0/mods-enabled/sql_redbacks 
   postgresql { 
   	send_application_name = no 
   } 
rlm_sql (sql_psql_redbacks): Attempting to connect to database "radius" 
rlm_sql (sql_psql_redbacks): Initialising connection pool 
   pool { 
   	start = 5 
   	min = 5 
   	max = 10 
   	spare = 3 
   	uses = 0 
   	lifetime = 0 
   	cleanup_interval = 30 
   	idle_timeout = 60 
   	retry_delay = 1 
   	spread = no 
   } 
rlm_sql (sql_psql_redbacks): Opening additional connection (0), 1 of 10 pending slots used 
Connected to database 'radius' on 'localhost' server version 90513, protocol version 3, backend PID 30173  
  # Instantiating module "reject" from file /etc/freeradius/3.0/mods-enabled/always 
  # Instantiating module "fail" from file /etc/freeradius/3.0/mods-enabled/always 
  # Instantiating module "ok" from file /etc/freeradius/3.0/mods-enabled/always 
  # Instantiating module "handled" from file /etc/freeradius/3.0/mods-enabled/always 
  # Instantiating module "invalid" from file /etc/freeradius/3.0/mods-enabled/always 
  # Instantiating module "userlock" from file /etc/freeradius/3.0/mods-enabled/always 
  # Instantiating module "notfound" from file /etc/freeradius/3.0/mods-enabled/always 
  # Instantiating module "noop" from file /etc/freeradius/3.0/mods-enabled/always 
  # Instantiating module "updated" from file /etc/freeradius/3.0/mods-enabled/always 
  # Instantiating module "preprocess" from file /etc/freeradius/3.0/mods-enabled/preprocess 
reading pairlist file /etc/freeradius/3.0/mods-config/preprocess/huntgroups 
reading pairlist file /etc/freeradius/3.0/mods-config/preprocess/hints 
  # Instantiating module "etc_passwd" from file /etc/freeradius/3.0/mods-enabled/passwd 
rlm_passwd: nfields: 3 keyfield 0(User-Name) listable: no 
  # Instantiating module "pap" from file /etc/freeradius/3.0/mods-enabled/pap 
  # Instantiating module "auth_log" from file /etc/freeradius/3.0/mods-enabled/detail.log 
rlm_detail (auth_log): 'User-Password' suppressed, will not appear in detail output 
  # Instantiating module "reply_log" from file /etc/freeradius/3.0/mods-enabled/detail.log 
  # Instantiating module "pre_proxy_log" from file /etc/freeradius/3.0/mods-enabled/detail.log 
  # Instantiating module "post_proxy_log" from file /etc/freeradius/3.0/mods-enabled/detail.log 
  # Instantiating module "mschap" from file /etc/freeradius/3.0/mods-enabled/mschap 
rlm_mschap (mschap): using internal authentication 
  # Instantiating module "files" from file /etc/freeradius/3.0/mods-enabled/files 
reading pairlist file /etc/freeradius/3.0/mods-config/files/authorize 
reading pairlist file /etc/freeradius/3.0/mods-config/files/accounting 
reading pairlist file /etc/freeradius/3.0/mods-config/files/pre-proxy 
  # Instantiating module "eap" from file /etc/freeradius/3.0/mods-enabled/eap 
   # Linked to sub-module rlm_eap_md5 
   # Linked to sub-module rlm_eap_leap 
   # Linked to sub-module rlm_eap_gtc 
   gtc { 
   	challenge = "Password: " 
   	auth_type = "PAP" 
   } 
   # Linked to sub-module rlm_eap_tls 
   tls { 
   	tls = "tls-common" 
   } 
   tls-config tls-common { 
   	verify_depth = 0 
   	ca_path = "/etc/freeradius/3.0/certs" 
   	pem_file_type = yes 
   	private_key_file = "/etc/ssl/private/ssl-cert-snakeoil.key" 
   	certificate_file = "/etc/ssl/certs/ssl-cert-snakeoil.pem" 
   	ca_file = "/etc/ssl/certs/ca-certificates.crt" 
   	private_key_password = <<< secret >>> 
   	dh_file = "/etc/freeradius/3.0/certs/dh" 
   	fragment_size = 1024 
   	include_length = yes 
   	auto_chain = yes 
   	check_crl = no 
   	check_all_crl = no 
   	cipher_list = "DEFAULT" 
   	ecdh_curve = "prime256v1" 
    cache { 
    	enable = yes 
    	lifetime = 24 
    	max_entries = 255 
    } 
    verify { 
    	skip_if_ocsp_ok = no 
    } 
    ocsp { 
    	enable = no 
    	override_cert_url = yes 
    	url = "http://127.0.0.1/ocsp/" 
    	use_nonce = yes 
    	timeout = 0 
    	softfail = no 
    } 
   } 
   # Linked to sub-module rlm_eap_ttls 
   ttls { 
   	tls = "tls-common" 
   	default_eap_type = "md5" 
   	copy_request_to_tunnel = no 
   	use_tunneled_reply = no 
   	virtual_server = "inner-tunnel" 
   	include_length = yes 
   	require_client_cert = no 
   } 
tls: Using cached TLS configuration from previous invocation 
   # Linked to sub-module rlm_eap_peap 
   peap { 
   	tls = "tls-common" 
   	default_eap_type = "mschapv2" 
   	copy_request_to_tunnel = no 
   	use_tunneled_reply = no 
   	proxy_tunneled_request_as_eap = yes 
   	virtual_server = "inner-tunnel" 
   	soh = no 
   	require_client_cert = no 
   } 
tls: Using cached TLS configuration from previous invocation 
   # Linked to sub-module rlm_eap_mschapv2 
   mschapv2 { 
   	with_ntdomain_hack = no 
   	send_error = no 
   } 
  # Instantiating module "cache_eap" from file /etc/freeradius/3.0/mods-enabled/cache_eap 
rlm_cache (cache_eap): Driver rlm_cache_rbtree (module rlm_cache_rbtree) loaded and linked 
  # Instantiating module "attr_filter.post-proxy" from file /etc/freeradius/3.0/mods-enabled/attr_filter 
reading pairlist file /etc/freeradius/3.0/mods-config/attr_filter/post-proxy 
  # Instantiating module "attr_filter.pre-proxy" from file /etc/freeradius/3.0/mods-enabled/attr_filter 
reading pairlist file /etc/freeradius/3.0/mods-config/attr_filter/pre-proxy 
  # Instantiating module "attr_filter.access_reject" from file /etc/freeradius/3.0/mods-enabled/attr_filter 
reading pairlist file /etc/freeradius/3.0/mods-config/attr_filter/access_reject 
[/etc/freeradius/3.0/mods-config/attr_filter/access_reject]:11 Check item "FreeRADIUS-Response-Delay" 	found in filter list for realm "DEFAULT".  
[/etc/freeradius/3.0/mods-config/attr_filter/access_reject]:11 Check item "FreeRADIUS-Response-Delay-USec" 	found in filter list for realm "DEFAULT".  
  # Instantiating module "attr_filter.access_challenge" from file /etc/freeradius/3.0/mods-enabled/attr_filter 
reading pairlist file /etc/freeradius/3.0/mods-config/attr_filter/access_challenge 
  # Instantiating module "attr_filter.accounting_response" from file /etc/freeradius/3.0/mods-enabled/attr_filter 
reading pairlist file /etc/freeradius/3.0/mods-config/attr_filter/accounting_response 
  # Instantiating module "IPASS" from file /etc/freeradius/3.0/mods-enabled/realm 
  # Instantiating module "suffix" from file /etc/freeradius/3.0/mods-enabled/realm 
  # Instantiating module "realmpercent" from file /etc/freeradius/3.0/mods-enabled/realm 
  # Instantiating module "ntdomain" from file /etc/freeradius/3.0/mods-enabled/realm 
  # Instantiating module "expiration" from file /etc/freeradius/3.0/mods-enabled/expiration 
 } # modules 
radiusd: #### Loading Virtual Servers #### 
server { # from file /etc/freeradius/3.0/radiusd.conf 
} # server 
server radius-test { # from file /etc/freeradius/3.0/sites-enabled/radius-test 
 # Loading authenticate {...} 
 # Loading authorize {...} 
 # Loading preacct {...} 
 # Loading accounting {...} 
 # Loading post-auth {...} 
} # server radius-test 
radiusd: #### Opening IP addresses and Ports #### 
listen { 
  	type = "auth" 
  	ipaddr = 192.168.10.31 
  	port = 1812 
  client redback-test.systemec.private { 
  	ipaddr = 192.168.10.10 
  	require_message_authenticator = no 
  	secret = <<< secret >>> 
  	shortname = "test-redback" 
   limit { 
   	max_connections = 16 
   	lifetime = 0 
   	idle_timeout = 30 
   } 
  } 
} 
listen { 
  	type = "acct" 
  	ipaddr = 192.168.10.31 
  	port = 1813 
} 
Listening on auth address 192.168.10.31 port 1812 bound to server radius-test 
Listening on acct address 192.168.10.31 port 1813 bound to server radius-test 
Listening on proxy address * port 52833 
Ready to process requests 

{...abridged...}

(65) Received Access-Request Id 35 from 192.168.10.10:1812 to 192.168.10.31:1812 length 127 
(65)   User-Name = "rb1-am-spare.2.1.393" 
(65)   User-Password = "Redback" 
(65)   Service-Type = Outbound-User 
(65)   NAS-Identifier = "rb1-am-spare" 
(65)   NAS-IP-Address = 172.16.0.64 
(65)   NAS-Port = 16842817 
(65)   NAS-Port-Type = Async 
(65)   Platform-Type = SE-100 
(65)   OS-Version = "12.1.1.12" 
(65) # Executing section authorize from file /etc/freeradius/3.0/sites-enabled/radius-test 
(65)   authorize { 
(65)     [chap] = noop 
(65) eap: No EAP-Message, not doing EAP 
(65)     [eap] = noop 
(65)     if (&Service-Type == Outbound-User) { 
(65)     if (&Service-Type == Outbound-User)  -> TRUE 
(65)     if (&Service-Type == Outbound-User)  { 
(65)       update control { 
(65)         &Huntgroup-Name := 'circuits' 
(65)       } # update control = noop 
(65)       [ok] = ok 
(65)     } # if (&Service-Type == Outbound-User)  = ok 
(65) sql_psql_redbacks_full: EXPAND %{User-Name} 
(65) sql_psql_redbacks_full:    --> rb1-am-spare.2.1.393 
(65) sql_psql_redbacks_full: SQL-User-Name set to 'rb1-am-spare.2.1.393' 
rlm_sql (sql_psql_redbacks_full): Closing connection (37): Hit idle_timeout, was idle for 97 seconds 
rlm_sql (sql_psql_redbacks_full): You probably need to lower "min" 
rlm_sql_postgresql: Socket destructor called, closing socket 
rlm_sql (sql_psql_redbacks_full): Reserved connection (35) 
(65) sql_psql_redbacks_full: EXPAND SELECT id, UserName, Attribute, Value, Op FROM radcheck WHERE Username = '%{SQL-User-Name}' ORDER BY id 
(65) sql_psql_redbacks_full:    --> SELECT id, UserName, Attribute, Value, Op FROM radcheck WHERE Username = 'rb1-am-spare.2.1.393' ORDER BY id 
(65) sql_psql_redbacks_full: Executing select query: SELECT id, UserName, Attribute, Value, Op FROM radcheck WHERE Username = 'rb1-am-spare.2.1.393' ORDER BY id 
rlm_sql_postgresql: Status: PGRES_TUPLES_OK 
rlm_sql_postgresql: query affected rows = 2 , fields = 5 
(65) sql_psql_redbacks_full: User found in radcheck table 
(65) sql_psql_redbacks_full: Conditional check items matched, merging assignment check items 
(65) sql_psql_redbacks_full:   Auth-Type := pap 
(65) sql_psql_redbacks_full:   Cleartext-Password := "Redback" 
(65) sql_psql_redbacks_full: EXPAND SELECT id, UserName, Attribute, Value, Op FROM radreply WHERE Username = '%{SQL-User-Name}' ORDER BY id 
(65) sql_psql_redbacks_full:    --> SELECT id, UserName, Attribute, Value, Op FROM radreply WHERE Username = 'rb1-am-spare.2.1.393' ORDER BY id 
(65) sql_psql_redbacks_full: Executing select query: SELECT id, UserName, Attribute, Value, Op FROM radreply WHERE Username = 'rb1-am-spare.2.1.393' ORDER BY id 
rlm_sql_postgresql: Status: PGRES_TUPLES_OK 
rlm_sql_postgresql: query affected rows = 0 , fields = 5 
(65) sql_psql_redbacks_full: EXPAND SELECT GroupName FROM radusergroup WHERE UserName='%{SQL-User-Name}' ORDER BY priority 
(65) sql_psql_redbacks_full:    --> SELECT GroupName FROM radusergroup WHERE UserName='rb1-am-spare.2.1.393' ORDER BY priority 
(65) sql_psql_redbacks_full: Executing select query: SELECT GroupName FROM radusergroup WHERE UserName='rb1-am-spare.2.1.393' ORDER BY priority 
rlm_sql_postgresql: Status: PGRES_TUPLES_OK 
rlm_sql_postgresql: query affected rows = 1 , fields = 1 
(65) sql_psql_redbacks_full: User found in the group table 
(65) sql_psql_redbacks_full: EXPAND SELECT id, GroupName, Attribute, Value, op FROM radgroupcheck WHERE GroupName = '%{SQL-Group}' ORDER BY id 
(65) sql_psql_redbacks_full:    --> SELECT id, GroupName, Attribute, Value, op FROM radgroupcheck WHERE GroupName = '' ORDER BY id 
(65) sql_psql_redbacks_full: Executing select query: SELECT id, GroupName, Attribute, Value, op FROM radgroupcheck WHERE GroupName = '' ORDER BY id 
rlm_sql_postgresql: Status: PGRES_TUPLES_OK 
rlm_sql_postgresql: query affected rows = 0 , fields = 5 
(65) sql_psql_redbacks_full: Group "circuits": Conditional check items matched 
(65) sql_psql_redbacks_full: Group "circuits": Merging assignment check items 
(65) sql_psql_redbacks_full: EXPAND SELECT id, GroupName, Attribute, Value, op FROM radgroupreply WHERE GroupName = '%{SQL-Group}' ORDER BY id 
(65) sql_psql_redbacks_full:    --> SELECT id, GroupName, Attribute, Value, op FROM radgroupreply WHERE GroupName = '' ORDER BY id 
(65) sql_psql_redbacks_full: Executing select query: SELECT id, GroupName, Attribute, Value, op FROM radgroupreply WHERE GroupName = '' ORDER BY id 
rlm_sql_postgresql: Status: PGRES_TUPLES_OK 
rlm_sql_postgresql: query affected rows = 0 , fields = 5 
(65) sql_psql_redbacks_full: Group "circuits": Merging reply items 
rlm_sql (sql_psql_redbacks_full): Released connection (35) 
rlm_sql (sql_psql_redbacks_full): Need 1 more connections to reach 10 spares 
rlm_sql (sql_psql_redbacks_full): Opening additional connection (39), 1 of 30 pending slots used 
Connected to database 'radius' on '/var/run/postgresql' server version 90513, protocol version 3, backend PID 29832  
(65)     [sql_psql_redbacks_full] = ok 
(65)   } # authorize = ok 
(65) Found Auth-Type = pap 
(65) # Executing group from file /etc/freeradius/3.0/sites-enabled/radius-test 
(65)   Auth-Type PAP { 
(65) pap: Login attempt with password 
(65) pap: Comparing with "known good" Cleartext-Password 
(65) pap: User authenticated successfully 
(65)     [pap] = ok 
(65)     update reply { 
(65)       &Reply-Message = 'PAP auth selected.' 
(65)     } # update reply = noop 
(65)   } # Auth-Type PAP = ok 
(65) # Executing section post-auth from file /etc/freeradius/3.0/sites-enabled/radius-test 
(65) Sent Access-Accept Id 35 from 192.168.10.31:1812 to 192.168.10.10:1812 length 0 
(65)   Reply-Message = "PAP auth selected." 
(65) Finished request 

As you can see, it correctly identifies that the user is in group 'circuits' and claims to merge the reply items, however, the Access-Accept packet contains no attributes.

This is the output from the SQL query:

radius=# SELECT id, GroupName, Attribute, Value, op FROM radgroupreply WHERE GroupName ='circuits' ORDER BY id;
 id | groupname |       attribute        |           value            | op 
----+-----------+------------------------+----------------------------+----
  1 | circuits  | PVC-Encapsulation-Type | AAA-ENCAPS-ETH-DOT1Q-PPPOE | :=
  2 | circuits  | Bind-Type              | AAA-AUTH-BIND              | :=
  3 | circuits  | Bind-Auth-Protocol     | AAA-PPP-PAP                | :=
  4 | circuits  | Service-Type           | Dialout-Framed-User        | :=
(4 rows)

Clearly, I've done something wrong /somewhere/ but I can't for the life of me figure out /what/. Any pointers where I should start looking?

--Rens Houben