search

FreeRADIUS / freeradius-server

FreeRADIUS - A multi-protocol policy server.
http://freeradius.org
GNU General Public License v2.0
2.09k stars 1.07k forks source link

freeradius 3.0.6 crashing on roaming accounting stop message #868

Closed ruyrybeyro closed 9 years ago

ruyrybeyro commented 9 years ago

Hi,

freeradius is crashing when roaming accounting data. Upon further tests it appears to crash when roaming accounting stop messages. Debian 8 was used, and the developer option was enable to further debug the problem.

Further follows the debug, the gdb output. I tried to attach valgrind, but said body too long. The valgrind info is at wget http://iscte.pt/~rffro/valgring.txt

As a side note, the instructions for debugging lack the note to change allow_core_dumps to yes.

Regards, Rui Ribeiro

radius2:/tmp# freeradius -X freeradius: FreeRADIUS Version 3.0.6, for host x86_64-pc-linux-gnu, built on Jan 2 2015 at 22:41:18 Copyright (C) 1999-2014 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/dictionary including configuration file /etc/freeradius/radiusd.conf including configuration file /etc/freeradius/proxy.conf including configuration file /etc/freeradius/clients.conf including files in directory /etc/freeradius/mods-enabled/ including configuration file /etc/freeradius/mods-enabled/logintime including configuration file /etc/freeradius/mods-enabled/cache including configuration file /etc/freeradius/mods-enabled/f_ticks including configuration file /etc/freeradius/mods-enabled/always including configuration file /etc/freeradius/mods-enabled/eap including configuration file /etc/freeradius/mods-enabled/detail.log including configuration file /etc/freeradius/mods-enabled/preprocess including configuration file /etc/freeradius/mods-enabled/attr_filter including configuration file /etc/freeradius/mods-enabled/ldap including configuration file /etc/freeradius/mods-enabled/linelog including configuration file /etc/freeradius/mods-enabled/files including configuration file /etc/freeradius/mods-enabled/unpack including configuration file /etc/freeradius/mods-enabled/utf8 including configuration file /etc/freeradius/mods-enabled/cache_eap including configuration file /etc/freeradius/mods-enabled/expr including configuration file /etc/freeradius/mods-enabled/detail including configuration file /etc/freeradius/mods-enabled/sql including configuration file /etc/freeradius/mods-config/sql/main/mysql/queries.conf including configuration file /etc/freeradius/mods-enabled/mschap including configuration file /etc/freeradius/mods-enabled/realm including files in directory /etc/freeradius/policy.d/ including configuration file /etc/freeradius/policy.d/debug including configuration file /etc/freeradius/policy.d/eap including configuration file /etc/freeradius/policy.d/operator-name including configuration file /etc/freeradius/policy.d/canonicalization including configuration file /etc/freeradius/policy.d/accounting including configuration file /etc/freeradius/policy.d/abfab-tr including configuration file /etc/freeradius/policy.d/cui including configuration file /etc/freeradius/policy.d/dhcp including configuration file /etc/freeradius/policy.d/local_blacklist including configuration file /etc/freeradius/policy.d/control including configuration file /etc/freeradius/policy.d/filter including files in directory /etc/freeradius/sites-enabled/ including configuration file /etc/freeradius/sites-enabled/inner-tunnel including configuration file /etc/freeradius/sites-enabled/default including configuration file /etc/freeradius/sites-enabled/status including configuration file /etc/freeradius/sites-enabled/control-socket main { security { user = "freerad" group = "freerad" allow_core_dumps = yes } } Core dumps are enabled 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 = 10024 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" } security { max_attributes = 200 reject_delay = 1.000000 status_server = yes } } radiusd: #### Loading Realms and Home Servers #### home_server mymaster { ipaddr = 193.136.188.36 port = 1813 type = "acct" secret = <<< secret >>> response_window = 30.000000 response_timeouts = 1 max_outstanding = 65536 zombie_period = 40 status_check = "none" ping_interval = 30 check_interval = 30 check_timeout = 4 num_answers_to_alive = 3 revive_interval = 300 coa { irt = 2 mrt = 16 mrc = 5 mrd = 30 } limit { max_connections = 16 max_requests = 0 lifetime = 0 idle_timeout = 0 } } home_server cv-radius { ipaddr = 193.136.192.43 port = 1812 type = "auth+acct" secret = <<< secret >>> response_window = 30.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 = 300 coa { irt = 2 mrt = 16 mrc = 5 mrd = 30 } limit { max_connections = 16 max_requests = 0 lifetime = 0 idle_timeout = 0 } } home_server cv2-radius { ipaddr = 193.136.192.44 port = 1812 type = "auth+acct" secret = <<< secret >>> response_window = 30.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 = 300 coa { irt = 2 mrt = 16 mrc = 5 mrd = 30 } limit { max_connections = 16 max_requests = 0 lifetime = 0 idletimeout = 0 } } realm iscte.pt { nostrip authhost = LOCAL accthost = LOCAL } realm ~..intranet$ { } realm ~..intra$ { } realm ~..iscte-iul.pt$ { } realm myabc.com { } realm ~.3gppnetwork.org$ { } realm LOCAL { } realm NULL { } home_server_pool EDUROAM { type = fail-over home_server = cv-radius homeserver = cv2-radius } realm ~.@~.* { pool = EDUROAM nostrip } realm TO_EDUROAM { pool = EDUROAM nostrip } radiusd: #### Loading Clients #### client localhost { ipaddr = 127.0.0.1 require_message_authenticator = no secret = <<< secret >>> nas_type = "other" limit { max_connections = 16 lifetime = 0 idle_timeout = 30 } } client 10.10.32.94 { ipaddr = 10.10.32.94/32 require_message_authenticator = no secret = <<< secret >>> nas_type = "other" limit { max_connections = 16 lifetime = 0 idle_timeout = 30 } } client 95.94.70.135 { ipaddr = 95.94.70.135/32 require_message_authenticator = no secret = <<< secret >>> nas_type = "other" limit { max_connections = 16 lifetime = 0 idle_timeout = 30 } } client 193.136.188.37 { ipaddr = 193.136.188.37 require_message_authenticator = no secret = <<< secret >>> nas_type = "other" limit { max_connections = 16 lifetime = 0 idle_timeout = 30 } } client 193.136.188.36 { ipaddr = 193.136.188.36/32 require_message_authenticator = no secret = <<< secret >>> nas_type = "other" limit { max_connections = 16 lifetime = 0 idle_timeout = 30 } } client 193.136.188.38 { ipaddr = 193.136.188.38/32 require_message_authenticator = no secret = <<< secret >>> nas_type = "other" limit { max_connections = 16 lifetime = 0 idle_timeout = 30 } } client 10.10.66.18/32 { ipaddr = 10.10.66.18/32 require_message_authenticator = no secret = <<< secret >>> shortname = "nut" nas_type = "other" limit { max_connections = 16 lifetime = 0 idle_timeout = 30 } } client 10.10.65.0/24 { ipaddr = 10.10.65.0/24 require_message_authenticator = no secret = <<< secret >>> shortname = "rede1_aps" nas_type = "cisco" limit { max_connections = 16 lifetime = 0 idle_timeout = 30 } } client 10.10.66.0/24 { ipaddr = 10.10.66.0/24 require_message_authenticator = no secret = <<< secret >>> shortname = "rede2_aps" nas_type = "cisco" limit { max_connections = 16 lifetime = 0 idle_timeout = 30 } } client 10.10.32.35/32 { ipaddr = 10.10.32.35/32 require_message_authenticator = no secret = <<< secret >>> shortname = "syslog" nas_type = "other" limit { max_connections = 16 lifetime = 0 idle_timeout = 30 } } client 10.61.10.11/32 { ipaddr = 10.61.10.11/32 require_message_authenticator = no secret = <<< secret >>> shortname = "meruc" nas_type = "other" limit { max_connections = 16 lifetime = 0 idle_timeout = 30 } } client 10.61.10.12/32 { ipaddr = 10.61.10.12/32 require_message_authenticator = no secret = <<< secret >>> shortname = "mc1550v" nas_type = "other" limit { max_connections = 16 lifetime = 0 idle_timeout = 30 } } client 193.136.192.43 { ipaddr = 193.136.192.43 require_message_authenticator = no secret = <<< secret >>> shortname = "proxyNacional1" nas_type = "other" limit { max_connections = 16 lifetime = 0 idle_timeout = 30 } } client 193.136.192.44 { ipaddr = 193.136.192.44 require_message_authenticator = no secret = <<< secret >>> shortname = "proxyNacional2" nas_type = "other" limit { max_connections = 16 lifetime = 0 idle_timeout = 30 } } Debugger not attached radiusd: #### Instantiating modules #### instantiate { } modules {

Loaded module rlm_logintime

Instantiating module "logintime" from file /etc/freeradius/mods-enabled/logintime

logintime { minimum_timeout = 60 }

Loaded module rlm_cache

Instantiating module "cache" from file /etc/freeradius/mods-enabled/cache

cache { driver = "rlm_cache_rbtree" key = "%{User-Name}" ttl = 10 max_entries = 0 epoch = 0 add_stats = no } rlm_cahe (cache): Driver rlm_cache_rbtree (module rlm_cache_rbtree) loaded and linked

Loaded module rlm_linelog

Instantiating module "f_ticks" from file /etc/freeradius/mods-enabled/f_ticks

linelog f_ticks { filename = "/var/log/freeradius/awesant/Stats-Awesant-Auth.log" permissions = 384 format = "" reference = "f_ticks.%{%{reply:Packet-Type}:-format}" }

Instantiating module "eduroam_log" from file /etc/freeradius/mods-enabled/f_ticks

linelog eduroam_log { filename = "syslog" permissions = 384 format = "" reference = "eduroam_log.%{%{reply:Packet-Type}:-format}" }

Instantiating module "inner_auth_log" from file /etc/freeradius/mods-enabled/f_ticks

linelog inner_auth_log { filename = "syslog" permissions = 384 format = "" reference = "inner_auth_log.%{%{reply:Packet-Type}:-format}" }

Instantiating module "Accounting-Request" from file /etc/freeradius/mods-enabled/f_ticks

linelog Accounting-Request { filename = "/var/log/freeradius/awesant/Stats-Awesant-Acct.log" permissions = 384 format = "" reference = "Accounting-Request.%{%{Acct-Status-Type}:-unknown}" }

Loaded module rlm_always

Instantiating module "reject" from file /etc/freeradius/mods-enabled/always

always reject { rcode = "reject" simulcount = 0 mpp = no }

Instantiating module "fail" from file /etc/freeradius/mods-enabled/always

always fail { rcode = "fail" simulcount = 0 mpp = no }

Instantiating module "ok" from file /etc/freeradius/mods-enabled/always

always ok { rcode = "ok" simulcount = 0 mpp = no }

Instantiating module "handled" from file /etc/freeradius/mods-enabled/always

always handled { rcode = "handled" simulcount = 0 mpp = no }

Instantiating module "invalid" from file /etc/freeradius/mods-enabled/always

always invalid { rcode = "invalid" simulcount = 0 mpp = no }

Instantiating module "userlock" from file /etc/freeradius/mods-enabled/always

always userlock { rcode = "userlock" simulcount = 0 mpp = no }

Instantiating module "notfound" from file /etc/freeradius/mods-enabled/always

always notfound { rcode = "notfound" simulcount = 0 mpp = no }

Instantiating module "noop" from file /etc/freeradius/mods-enabled/always

always noop { rcode = "noop" simulcount = 0 mpp = no }

Instantiating module "updated" from file /etc/freeradius/mods-enabled/always

always updated { rcode = "updated" simulcount = 0 mpp = no }

Loaded module rlm_eap

Instantiating module "eap" from file /etc/freeradius/mods-enabled/eap

eap { default_eap_type = "peap" timer_expire = 60 ignore_unknown_eap_types = no mod_accounting_username_bug = no max_sessions = 10024 }

Linked to sub-module rlm_eap_ttls

ttls { tls = "tls-common" default_eap_type = "mschapv2" copy_request_to_tunnel = yes use_tunneled_reply = yes virtual_server = "inner-tunnel" include_length = yes require_client_cert = no } tls-config tls-common { rsa_key_exchange = no dh_key_exchange = yes rsa_key_length = 512 dh_key_length = 512 verify_depth = 0 pem_file_type = yes private_key_file = "/etc/freeradius/certs/key.pem" certificate_file = "/etc/freeradius/certs/server.pem" private_key_password = <<< secret >>> dh_file = "/etc/freeradius/certs/dh" fragment_size = 1024 include_length = yes check_crl = no cipher_list = "DEFAULT" ecdh_curve = "prime256v1" cache { enable = yes lifetime = 24 max_entries = 255 } verify { } 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_peap

peap { tls = "tls-common" default_method = "mschapv2" copy_request_to_tunnel = yes use_tunneled_reply = yes proxy_tunneled_request_as_eap = yes virtual_server = "inner-tunnel" soh = no require_client_cert = no } Using cached TLS configuration from previous invocation

Linked to sub-module rlm_eap_mschapv2

mschapv2 { with_ntdomain_hack = no send_error = no }

Loaded module rlm_detail

Instantiating module "auth_log" from file /etc/freeradius/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 } rlm_detail (auth_log): 'User-Password' suppressed, will not appear in detail output

Instantiating module "reply_log" from file /etc/freeradius/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 }

Instantiating module "pre_proxy_log" from file /etc/freeradius/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 }

Instantiating module "post_proxy_log" from file /etc/freeradius/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 }

Loaded module rlm_preprocess

Instantiating module "preprocess" from file /etc/freeradius/mods-enabled/preprocess

preprocess { huntgroups = "/etc/freeradius/mods-config/preprocess/huntgroups" hints = "/etc/freeradius/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 } reading pairlist file /etc/freeradius/mods-config/preprocess/huntgroups reading pairlist file /etc/freeradius/mods-config/preprocess/hints

Loaded module rlm_attr_filter

Instantiating module "attr_filter.post-proxy" from file /etc/freeradius/mods-enabled/attr_filter

attr_filter attr_filter.post-proxy { filename = "/etc/freeradius/mods-config/attr_filter/post-proxy" key = "%{Realm}" relaxed = no } reading pairlist file /etc/freeradius/mods-config/attr_filter/post-proxy [/etc/freeradius/mods-config/attr_filter/post-proxy]:1 Check item "Cached-Session-Policy" found in filter list for realm "DEFAULT".

Instantiating module "attr_filter.pre-proxy" from file /etc/freeradius/mods-enabled/attr_filter

attr_filter attr_filter.pre-proxy { filename = "/etc/freeradius/mods-config/attr_filter/pre-proxy" key = "%{Realm}" relaxed = no } reading pairlist file /etc/freeradius/mods-config/attr_filter/pre-proxy

Instantiating module "attr_filter.access_reject" from file /etc/freeradius/mods-enabled/attr_filter

attr_filter attr_filter.access_reject { filename = "/etc/freeradius/mods-config/attr_filter/access_reject" key = "%{User-Name}" relaxed = no } reading pairlist file /etc/freeradius/mods-config/attr_filter/access_reject

Instantiating module "attr_filter.access_challenge" from file /etc/freeradius/mods-enabled/attr_filter

attr_filter attr_filter.access_challenge { filename = "/etc/freeradius/mods-config/attr_filter/access_challenge" key = "%{User-Name}" relaxed = no } reading pairlist file /etc/freeradius/mods-config/attr_filter/access_challenge

Instantiating module "attr_filter.accounting_response" from file /etc/freeradius/mods-enabled/attr_filter

attr_filter attr_filter.accounting_response { filename = "/etc/freeradius/mods-config/attr_filter/accounting_response" key = "%{User-Name}" relaxed = no } reading pairlist file /etc/freeradius/mods-config/attr_filter/accounting_response

Loaded module rlm_ldap

Instantiating module "ldap" from file /etc/freeradius/mods-enabled/ldap

ldap { port = 0 password = <<< secret >>> identity = "CN=Radius,CN=Users,DC=xxxxx,DC=xxxx" user { filter = "(sAMAccountName=%{Stripped-User-Name})" scope = "sub" base_dn = "CN=Users,DC=wiscte,DC=wfarm" access_positive = yes } group { scope = "sub" base_dn = "CN=Users,DC=xxxx,DC=xxxxx" name_attribute = "cn" membership_attribute = "memberOf" membership_filter = "(sAMAccountName=%{Stripped-User-Name})" cacheable_name = no cacheable_dn = no } client { filter = "(objectClass=frClient)" scope = "sub" base_dn = "DC=xxxxx,DC=xxxxx" } profile { filter = "(&)" } options { ldap_debug = 40 chase_referrals = yes rebind = yes net_timeout = 1 res_timeout = 20 srv_timelimit = 20 idle = 60 probes = 3 interval = 3 } tls { start_tls = no } } rlm_ldap: Falling back to build time libldap version info. Query for LDAP_OPT_API_INFO returned: -1 rlm_ldap: libldap vendor: OpenLDAP, version: 2.4.40 accounting { reference = "%{tolower:type.%{Acct-Status-Type}}" } post-auth { reference = "." } rlm_ldap (ldap): Initialising connection pool pool { start = 5 min = 1 max = 50 spare = 3 uses = 0 lifetime = 0 cleanup_interval = 30 idle_timeout = 60 retry_delay = 1 spread = no } rlm_ldap (ldap): Opening additional connection (0) rlm_ldap (ldap): Connecting to ldap://10.20.10.78:389 rlm_ldap (ldap): Waiting for bind result... rlm_ldap (ldap): Bind successful rlm_ldap (ldap): Opening additional connection (1) rlm_ldap (ldap): Connecting to ldap://10.20.10.78:389 rlm_ldap (ldap): Waiting for bind result... rlm_ldap (ldap): Bind successful rlm_ldap (ldap): Opening additional connection (2) rlm_ldap (ldap): Connecting to ldap://10.20.10.78:389 rlm_ldap (ldap): Waiting for bind result... rlm_ldap (ldap): Bind successful rlm_ldap (ldap): Opening additional connection (3) rlm_ldap (ldap): Connecting to ldap://10.20.10.78:389 rlm_ldap (ldap): Waiting for bind result... rlm_ldap (ldap): Bind successful rlm_ldap (ldap): Opening additional connection (4) rlm_ldap (ldap): Connecting to ldap://10.20.10.78:389 rlm_ldap (ldap): Waiting for bind result... rlm_ldap (ldap): Bind successful

Instantiating module "linelog" from file /etc/freeradius/mods-enabled/linelog

linelog { filename = "/var/log/freeradius/linelog" permissions = 384 format = "This is a log message for %{User-Name}" reference = "messages.%{%{Packet-Type}:-default}" }

Instantiating module "log_accounting" from file /etc/freeradius/mods-enabled/linelog

linelog log_accounting { filename = "/var/log/freeradius/linelog-accounting" permissions = 384 format = "" reference = "Accounting-Request.%{%{Acct-Status-Type}:-unknown}" }

Loaded module rlm_files

Instantiating module "files" from file /etc/freeradius/mods-enabled/files

files { filename = "/etc/freeradius/mods-config/files/authorize" usersfile = "/etc/freeradius/mods-config/files/authorize" acctusersfile = "/etc/freeradius/mods-config/files/accounting" preproxy_usersfile = "/etc/freeradius/mods-config/files/pre-proxy" compat = "cistron" } reading pairlist file /etc/freeradius/mods-config/files/authorize reading pairlist file /etc/freeradius/mods-config/files/authorize reading pairlist file /etc/freeradius/mods-config/files/accounting reading pairlist file /etc/freeradius/mods-config/files/pre-proxy [/etc/freeradius/mods-config/files/pre-proxy]:23 Cistron compatibility checks for entry DEFAULT ...

Loaded module rlm_unpack

Instantiating module "unpack" from file /etc/freeradius/mods-enabled/unpack

Loaded module rlm_utf8

Instantiating module "utf8" from file /etc/freeradius/mods-enabled/utf8

Instantiating module "cache_eap" from file /etc/freeradius/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 } rlm_cahe (cache_eap): Driver rlm_cache_rbtree (module rlm_cache_rbtree) loaded and linked

Loaded module rlm_expr

Instantiating module "expr" from file /etc/freeradius/mods-enabled/expr

expr { safecharacters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-: /" }

Instantiating module "detail" from file /etc/freeradius/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_sql

Instantiating module "sql" from file /etc/freeradius/mods-enabled/sql

sql { driver = "rlm_sql_mysql" server = "10.10.32.26" port = "" login = "radius" 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 = "" simul_verify_query = "SELECT radacctid, acctsessionid, username, nasipaddress, nasportid, framedipaddress, callingstationid, framedprotocol FROM radacct WHERE username = '%{SQL-User-Name}' AND acctstoptime IS NULL" safecharacters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-: /" accounting { reference = "%{tolower:type.%{Acct-Status-Type}.query}" type { accounting-on { query = "UPDATE radacct SET acctstoptime = FROM_UNIXTIME(%{integer:Event-Timestamp}), acctsessiontime = '%{integer:Event-Timestamp}' - UNIX_TIMESTAMP(acctstarttime), acctterminatecause = '%{%{Acct-Terminate-Cause}:-NAS-Reboot}' WHERE acctstoptime IS NULL AND nasipaddress = '%{NAS-IP-Address}' AND acctstarttime <= FROM_UNIXTIME(%{integer:Event-Timestamp})" } accounting-off { query = "UPDATE radacct SET acctstoptime = FROM_UNIXTIME(%{integer:Event-Timestamp}), acctsessiontime = '%{integer:Event-Timestamp}' - UNIX_TIMESTAMP(acctstarttime), acctterminatecause = '%{%{Acct-Terminate-Cause}:-NAS-Reboot}' WHERE acctstoptime IS NULL AND nasipaddress = '%{NAS-IP-Address}' AND acctstarttime <= FROM_UNIXTIME(%{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}', '%{NAS-Port-Type}', FROM_UNIXTIME(%{integer:Event-Timestamp}), FROM_UNIXTIME(%{integer:Event-Timestamp}), 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 = (@acctupdatetime_old:=acctupdatetime), acctupdatetime = FROM_UNIXTIME(%{integer:Event-Timestamp}), acctinterval = %{integer:Event-Timestamp} - UNIX_TIMESTAMP(@acctupdatetime_old), framedipaddress = '%{Framed-IP-Address}', acctsessiontime = '%{Acct-Session-Time}', acctinputoctets = '%{%{Acct-Input-Gigawords}:-0}' << 32 | '%{%{Acct-Input-Octets}:-0}', acctoutputoctets = '%{%{Acct-Output-Gigawords}:-0}' << 32 | '%{%{Acct-Output-Octets}:-0}' WHERE acctsessionid = '%{Acct-Session-Id}' AND username = '%{SQL-User-Name}' AND nasipaddress = '%{NAS-IP-Address}'" } stop { query = "UPDATE radacct SET acctstoptime = FROM_UNIXTIME(%{integer:Event-Timestamp}), acctsessiontime = '%{Acct-Session-Time}', 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 acctsessionid = '%{Acct-Session-Id}' AND username = '%{SQL-User-Name}' AND nasipaddress = '%{NAS-IP-Address}'" } } } 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): simul_count_query is empty. Please delete it from the configuration mysql { tls { } } rlm_sql (sql): Driver rlm_sql_mysql (module rlm_sql_mysql) loaded and linked rlm_sql (sql): Attempting to connect to database "radius" rlm_sql (sql): Initialising connection pool pool { start = 5 min = 4 max = 50 spare = 20 uses = 0 lifetime = 0 cleanup_interval = 30 idle_timeout = 60 retry_delay = 1 spread = no } rlm_sql (sql): Opening additional connection (0) rlm_sql_mysql: Starting connect to MySQL server rlm_sql (sql): Opening additional connection (1) rlm_sql_mysql: Starting connect to MySQL server rlm_sql (sql): Opening additional connection (2) rlm_sql_mysql: Starting connect to MySQL server rlm_sql (sql): Opening additional connection (3) rlm_sql_mysql: Starting connect to MySQL server rlm_sql (sql): Opening additional connection (4) rlm_sql_mysql: Starting connect to MySQL server

Loaded module rlm_mschap

Instantiating module "mschap" from file /etc/freeradius/mods-enabled/mschap

mschap { use_mppe = yes require_encryption = yes require_strong = yes with_ntdomain_hack = yes ntlm_auth = "/usr/bin/ntlm_auth --request-nt-key --username=%{%{Stripped-User-Name}:-%{%{User-Name}:-None}} --challenge=%{%{mschap:Challenge}:-00} --nt-response=%{%{mschap:NT-Response}:-00}" passchange { } allow_retry = yes }

Loaded module rlm_realm

Instantiating module "IPASS" from file /etc/freeradius/mods-enabled/realm

realm IPASS { format = "prefix" delimiter = "/" ignore_default = no ignore_null = no }

Instantiating module "suffix" from file /etc/freeradius/mods-enabled/realm

realm suffix { format = "suffix" delimiter = "@" ignore_default = no ignore_null = no }

Instantiating module "realmpercent" from file /etc/freeradius/mods-enabled/realm

realm realmpercent { format = "suffix" delimiter = "%" ignore_default = no ignore_null = no }

Instantiating module "ntdomain" from file /etc/freeradius/mods-enabled/realm

realm ntdomain { format = "prefix" delimiter = "\" ignore_default = no ignore_null = no } } # modules radiusd: #### Loading Virtual Servers #### server { # from file /etc/freeradius/radiusd.conf } # server server inner-tunnel { # from file /etc/freeradius/sites-enabled/inner-tunnel

Creating Post-Proxy-Type = Fail

Loading authenticate {...}

Loading authorize {...}

Loading session {...}

Loading pre-proxy {...}

Loading post-proxy {...}

Loading post-auth {...}

} # server inner-tunnel server default { # from file /etc/freeradius/sites-enabled/default

Creating Autz-Type = Status-Server

Loading authenticate {...}

Loading authorize {...}

Loading preacct {...}

Loading accounting {...}

Loading session {...}

Loading pre-proxy {...}

Loading post-proxy {...}

Loading post-auth {...}

} # server default server status { # from file /etc/freeradius/sites-enabled/status

Loading authorize {...}

} # server status radiusd: #### Opening IP addresses and Ports #### listen { type = "control" listen { socket = "/var/run/freeradius/freeradius.sock" gid = "radius" mode = "rw" } } listen { type = "auth" ipaddr = 127.0.0.1 port = 18120 } listen { type = "auth" ipaddr = port = 0 limit { max_connections = 16 lifetime = 0 idle_timeout = 30 } } listen { type = "acct" ipaddr = port = 0 limit { max_connections = 16 lifetime = 0 idle_timeout = 30 } } listen { type = "status" ipaddr = 127.0.0.1 port = 18121 client admin { ipaddr = 127.0.0.1 require_message_authenticator = no secret = <<< secret >>> limit { max_connections = 16 lifetime = 0 idle_timeout = 30 } } } Listening on command file /var/run/freeradius/freeradius.sock Listening on auth address 127.0.0.1 port 18120 as server inner-tunnel Listening on auth address * port 1812 as server default Listening on acct address * port 1813 as server default Listening on status address 127.0.0.1 port 18121 as server status Opening new proxy socket 'proxy address * port 0' Listening on proxy address * port 38792 Ready to process requests (0) Received Access-Request Id 236 from 193.136.192.43:60069 to 193.136.188.36:1812 length 209 (0) Acct-Session-Id = 'a5409005-00000f4c' (0) NAS-Port = 3083 (0) NAS-Port-Type = Wireless-802.11 (0) NAS-Identifier = 'SG3503N21L' (0) NAS-IP-Address = 192.168.2.6 (0) User-Name = 'tvppn@iscte.pt' (0) Calling-Station-Id = '78-FD-94-6D-44-48' (0) Called-Station-Id = 'A0-48-1C-52-FE-70' (0) Service-Type = Framed-User (0) EAP-Message = 0x0252001301747670706e4069736374652e7074 (0) Message-Authenticator = 0xba3837478cb147a1a97f09db3c527ecf (0) Operator-Name = '1unl.pt' (0) Eduroam-SP-Country = 'PT' (0) Proxy-State = 0x4f53432d457874656e6465642d49643d33333038 (0) # Executing section authorize from file /etc/freeradius/sites-enabled/default (0) authorize { (0) if ( User-name == "radius-teste@iscte.pt" ) { (0) if ( User-name == "radius-teste@iscte.pt" ) -> FALSE (0) else { (0) auth_log: EXPAND /var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d (0) auth_log: --> /var/log/freeradius/radacct/193.136.192.43/auth-detail-20150102 (0) auth_log: /var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/193.136.192.43/auth-detail-20150102 (0) auth_log: EXPAND %t (0) auth_log: --> Fri Jan 2 22:52:50 2015 (0) [authlog] = ok (0) if (!(User-Name =~ /^([^@])@(.+)$/)) { (0) if (!(User-Name =~ /^([^@]_)@(.+)$/)) -> FALSE (0) else { (0) update request { (0) EXPAND %{1} (0) --> tvppn (0) Stripped-User-Name := "tvppn" (0) EXPAND %{2} (0) --> iscte.pt (0) Realm := "iscte.pt" (0) } # update request = noop (0) if ( (Realm == "iscte.pt") || ( Realm == "iscte-iul.pt" ) ) { (0) if ( (Realm == "iscte.pt") || ( Realm == "iscte-iul.pt" ) ) -> TRUE (0) if ( (Realm == "iscte.pt") || ( Realm == "iscte-iul.pt" ) ) { (0) update control { (0) Proxy-To-Realm := 'LOCAL' (0) } # update control = noop (0) } # if ( (Realm == "iscte.pt") || ( Realm == "iscte-iul.pt" ) ) = noop (0) ... skipping else for request 0: Preceding "if" was taken (0) } # else = noop (0) } # else = ok (0) eap: Peer sent code Response (2) ID 82 length 19 (0) eap: EAP-Identity reply, returning 'ok' so we can short-circuit the rest of authorize (0) [eap] = ok (0) } # authorize = ok (0) Found Auth-Type = EAP (0) # Executing group from file /etc/freeradius/sites-enabled/default (0) authenticate { (0) eap: Peer sent method Identity (1) (0) eap: Calling eap_peap to process EAP data (0) eap_peap: Flushing SSL sessions (of #0) (0) eap_peap: Initiate (0) eap_peap: Start returned 1 (0) eap: EAP session adding &reply:State = 0xec756863ec267142 (0) [eap] = handled (0) } # authenticate = handled (0) Sent Access-Challenge Id 236 from 193.136.188.36:1812 to 193.136.192.43:60069 length 86 (0) EAP-Message = 0x015300061920 (0) Message-Authenticator = 0x00000000000000000000000000000000 (0) State = 0xec756863ec26714299024245a825d349 (0) Proxy-State = 0x4f53432d457874656e6465642d49643d33333038 (0) Finished request Waking up in 0.3 seconds. Waking up in 4.6 seconds. (1) Received Access-Request Id 4 from 95.94.70.135:44306 to 193.136.188.36:1812 length 20 (1) # Executing section authorize from file /etc/freeradius/sites-enabled/default (1) authorize { (1) if ( User-name == "radius-teste@iscte.pt" ) { ERROR: (1) Failed retrieving values required to evaluate condition (1) else { (1) auth_log: EXPAND /var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d (1) auth_log: --> /var/log/freeradius/radacct/95.94.70.135/auth-detail-20150102 (1) auth_log: /var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/95.94.70.135/auth-detail-20150102 (1) auth_log: EXPAND %t (1) auth_log: --> Fri Jan 2 22:52:51 2015 (1) [auth_log] = ok (1) if (!(User-Name =~ /^([^@]*)@(.+)$/)) { ERROR: (1) Failed retrieving values required to evaluate condition (1) else { (1) update request { (1) EXPAND %{1} (1) --> (1) Stripped-User-Name := "" (1) EXPAND %{2} (1) --> (1) Realm := "" (1) } # update request = noop (1) if ( (Realm == "iscte.pt") || ( Realm == "iscte-iul.pt" ) ) { (1) if ( (Realm == "iscte.pt") || ( Realm == "iscte-iul.pt" ) ) -> FALSE (1) else { (1) update control { (1) Proxy-To-Realm := 'TO_EDUROAM' (1) } # update control = noop (1) } # else = noop (1) } # else = noop (1) } # else = ok (1) eap: No EAP-Message, not doing EAP (1) [eap] = noop (1) policy local_blacklist { (1) if (!(Calling-Station-Id)) { (1) if (!(Calling-Station-Id)) -> TRUE (1) if (!(Calling-Station-Id)) { (1) update reply { (1) Reply-Message := 'No Calling-Station-Id' (1) } # update reply = noop (1) [reject] = reject (1) } # if (!(Calling-Station-Id)) = reject (1) } # policy local_blacklist = reject (1) } # authorize = reject (1) Using Post-Auth-Type Reject (1) # Executing group from file /etc/freeradius/sites-enabled/default (1) Post-Auth-Type REJECT { (1) f_ticks: EXPAND f_ticks.%{%{reply:Packet-Type}:-format} (1) f_ticks: --> f_ticks.Access-Reject (1) f_ticks: EXPAND /var/log/freeradius/awesant/Stats-Awesant-Auth.log (1) f_ticks: --> /var/log/freeradius/awesant/Stats-Awesant-Auth.log (1) f_ticks: EXPAND AUTH-ID=%I#TIME=%l#REALM=%{Realm}#CSI=%{Calling-Station-Id}/%{Called-Station-Id}#USER=%{md5:%{User-Name}}#NASIP=%{NAS-IP-Address}#RESULT=FAIL (1) f_ticks: --> AUTH-ID=4#TIME=1420239171#REALM=#CSI=/#USER=#NASIP=#RESULT=FAIL (1) [f_ticks] = ok (1) sql: EXPAND .query (1) sql: --> .query (1) sql: Using query template 'query' rlm_sql (sql): Reserved connection (4) (1) sql: EXPAND %{User-Name} (1) sql: --> (1) sql: SQL-User-Name set to '' (1) sql: EXPAND INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '%{SQL-User-Name}', '%{%{User-Password}:-%{Chap-Password}}', '%{reply:Packet-Type}', '%S') (1) sql: --> INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '', '', 'Access-Reject', '2015-01-02 22:52:51') rlm_sql (sql): Executing query: 'INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '', '', 'Access-Reject', '2015-01-02 22:52:51')' rlm_sql (sql): Released connection (4) rlm_sql (sql): 0 of 5 connections in use. Need more spares rlm_sql (sql): Opening additional connection (5) rlm_sql_mysql: Starting connect to MySQL server (1) [sql] = ok (1) attr_filter.access_reject: EXPAND %{User-Name} (1) attr_filter.access_reject: --> (1) [attr_filter.access_reject] = noop (1) } # Post-Auth-Type REJECT = ok (1) Delaying response for 1.000000 seconds Waking up in 0.3 seconds. (2) Received Accounting-Request Id 83 from 95.94.70.135:44306 to 193.136.188.36:1813 length 26 (2) Acct-Status-Type = Start (2) # Executing section preacct from file /etc/freeradius/sites-enabled/default (2) preacct { (2) update request { (2) EXPAND %{expr: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0}} (2) --> 1420239171 (2) FreeRADIUS-Acct-Session-Start-Time = "Jan 2 2015 22:52:51 WET" (2) } # update request = noop (2) if (!Event-TimeStamp) { (2) if (!Event-TimeStamp) -> TRUE (2) if (!Event-TimeStamp) { (2) update request { (2) EXPAND %l (2) --> 1420239171 (2) Event-Timestamp := "Jan 2 2015 22:52:51 WET" (2) } # update request = noop (2) } # if (!Event-TimeStamp) = noop (2) policy acct_unique { (2) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) { (2) EXPAND %{string:Class} (2) --> (2) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) -> FALSE (2) else { (2) update request { (2) EXPAND %{md5:%{User-Name},%{Acct-Session-ID},%{%{NAS-IPv6-Address}:-%{NAS-IP-Address}},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}} (2) --> 8daa390830619c3758c0f67ab6e59c22 (2) &Acct-Unique-Session-Id := "8daa390830619c3758c0f67ab6e59c22" (2) } # update request = noop (2) } # else = noop (2) } # policy acct_unique = noop (2) [suffix] = noop (2) } # preacct = noop (2) # Executing section accounting from file /etc/freeradius/sites-enabled/default (2) accounting { (2) detail: EXPAND /var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d (2) detail: --> /var/log/freeradius/radacct/95.94.70.135/detail-20150102 (2) detail: /var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d expands to /var/log/freeradius/radacct/95.94.70.135/detail-20150102 (2) detail: EXPAND %t (2) detail: --> Fri Jan 2 22:52:51 2015 (2) [detail] = ok (2) sql: EXPAND %{tolower:type.%{Acct-Status-Type}.query} (2) sql: --> type.start.query (2) sql: Using query template 'query' rlm_sql (sql): Reserved connection (5) (2) sql: EXPAND %{User-Name} (2) sql: --> (2) sql: SQL-User-Name set to '' (2) sql: EXPAND 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}', '%{NAS-Port-Type}', FROM_UNIXTIME(%{integer:Event-Timestamp}), FROM_UNIXTIME(%{integer:Event-Timestamp}), NULL, '0', '%{Acct-Authentic}', '%{Connect-Info}', '', '0', '0', '%{Called-Station-Id}', '%{Calling-Station-Id}', '', '%{Service-Type}', '%{Framed-Protocol}', '%{Framed-IP-Address}') (2) sql: --> 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 ('', '8daa390830619c3758c0f67ab6e59c22', '', '', '', '', '', FROM_UNIXTIME(1420239171), FROM_UNIXTIME(1420239171), NULL, '0', '', '', '', '0', '0', '', '', '', '', '', '') rlm_sql (sql): Executing 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 ('', '8daa390830619c3758c0f67ab6e59c22', '', '', '', '', '', FROM_UNIXTIME(1420239171), FROM_UNIXTIME(1420239171), NULL, '0', '', '', '', '0', '0', '', '', '', '', '', '')' rlm_sql (sql): Released connection (5) (2) [sql] = ok (2) Accounting-Request: EXPAND Accounting-Request.%{%{Acct-Status-Type}:-unknown} (2) Accounting-Request: --> Accounting-Request.Start (2) Accounting-Request: EXPAND /var/log/freeradius/awesant/Stats-Awesant-Acct.log (2) Accounting-Request: --> /var/log/freeradius/awesant/Stats-Awesant-Acct.log (2) Accounting-Request: EXPAND ACCT-ID=%{Acct-Session-Id}#TIME=%l#TYPE=Start#CSI=%{Calling-Station-Id}/%{Called-Station-Id}#NASIP=%{NAS-IP-Address}#USER=%{md5:%{User-Name}}#REALM=%{Realm} (2) Accounting-Request: --> ACCT-ID=#TIME=1420239171#TYPE=Start#CSI=/#NASIP=#USER=#REALM= (2) [Accounting-Request] = ok (2) if (noop) { (2) if (noop) -> FALSE (2) attr_filter.accounting_response: EXPAND %{User-Name} (2) attr_filter.accounting_response: --> (2) [attr_filter.accounting_response] = noop (2) } # accounting = ok (2) Sent Accounting-Response Id 83 from 193.136.188.36:1813 to 95.94.70.135:44306 length 20 (2) Finished request Waking up in 0.3 seconds. (3) Received Accounting-Request Id 85 from 95.94.70.135:44306 to 193.136.188.36:1813 length 26 (3) Acct-Status-Type = Interim-Update (3) # Executing section preacct from file /etc/freeradius/sites-enabled/default (3) preacct { (3) update request { (3) EXPAND %{expr: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0}} (3) --> 1420239171 (3) FreeRADIUS-Acct-Session-Start-Time = "Jan 2 2015 22:52:51 WET" (3) } # update request = noop (3) if (!Event-TimeStamp) { (3) if (!Event-TimeStamp) -> TRUE (3) if (!Event-TimeStamp) { (3) update request { (3) EXPAND %l (3) --> 1420239171 (3) Event-Timestamp := "Jan 2 2015 22:52:51 WET" (3) } # update request = noop (3) } # if (!Event-TimeStamp) = noop (3) policy acct_unique { (3) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) { (3) EXPAND %{string:Class} (3) --> (3) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) -> FALSE (3) else { (3) update request { (3) EXPAND %{md5:%{User-Name},%{Acct-Session-ID},%{%{NAS-IPv6-Address}:-%{NAS-IP-Address}},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}} (3) --> 8daa390830619c3758c0f67ab6e59c22 (3) &Acct-Unique-Session-Id := "8daa390830619c3758c0f67ab6e59c22" (3) } # update request = noop (3) } # else = noop (3) } # policy acct_unique = noop (3) [suffix] = noop (3) } # preacct = noop (3) # Executing section accounting from file /etc/freeradius/sites-enabled/default (3) accounting { (3) detail: EXPAND /var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d (3) detail: --> /var/log/freeradius/radacct/95.94.70.135/detail-20150102 (3) detail: /var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d expands to /var/log/freeradius/radacct/95.94.70.135/detail-20150102 (3) detail: EXPAND %t (3) detail: --> Fri Jan 2 22:52:51 2015 (3) [detail] = ok (3) sql: EXPAND %{tolower:type.%{Acct-Status-Type}.query} (3) sql: --> type.interim-update.query (3) sql: Using query template 'query' rlm_sql (sql): Reserved connection (5) (3) sql: EXPAND %{User-Name} (3) sql: --> (3) sql: SQL-User-Name set to '' (3) sql: EXPAND UPDATE radacct SET acctupdatetime = (@acctupdatetime_old:=acctupdatetime), acctupdatetime = FROM_UNIXTIME(%{integer:Event-Timestamp}), acctinterval = %{integer:Event-Timestamp} - UNIX_TIMESTAMP(@acctupdatetime_old), framedipaddress = '%{Framed-IP-Address}', acctsessiontime = '%{Acct-Session-Time}', acctinputoctets = '%{%{Acct-Input-Gigawords}:-0}' << 32 | '%{%{Acct-Input-Octets}:-0}', acctoutputoctets = '%{%{Acct-Output-Gigawords}:-0}' << 32 | '%{%{Acct-Output-Octets}:-0}' WHERE acctsessionid = '%{Acct-Session-Id}' AND username = '%{SQL-User-Name}' AND nasipaddress = '%{NAS-IP-Address}' (3) sql: --> UPDATE radacct SET acctupdatetime = (@acctupdatetime_old:=acctupdatetime), acctupdatetime = FROM_UNIXTIME(1420239171), acctinterval = 1420239171 - UNIX_TIMESTAMP(@acctupdatetime_old), framedipaddress = '', acctsessiontime = '', acctinputoctets = '0' << 32 | '0', acctoutputoctets = '0' << 32 | '0' WHERE acctsessionid = '' AND username = '' AND nasipaddress = '' rlm_sql (sql): Executing query: 'UPDATE radacct SET acctupdatetime = (@acctupdatetime_old:=acctupdatetime), acctupdatetime = FROM_UNIXTIME(1420239171), acctinterval = 1420239171 - UNIX_TIMESTAMP(@acctupdatetime_old), framedipaddress = '', acctsessiontime = '', acctinputoctets = '0' << 32 | '0', acctoutputoctets = '0' << 32 | '0' WHERE acctsessionid = '' AND username = '' AND nasipaddress = ''' rlm_sql_mysql: Rows matched: 21 Changed: 21 Warnings: 21 rlm_sql (sql): Released connection (5) (3) [sql] = ok (3) Accounting-Request: EXPAND Accounting-Request.%{%{Acct-Status-Type}:-unknown} (3) Accounting-Request: --> Accounting-Request.Interim-Update No such configuration item .Accounting-Request.Interim-Update (3) Accounting-Request: No such entry ".Accounting-Request.Interim-Update" (3) [Accounting-Request] = noop (3) if (noop) { (3) if (noop) -> TRUE (3) if (noop) { (3) [ok] = ok (3) } # if (noop) = ok (3) attr_filter.accounting_response: EXPAND %{User-Name} (3) attr_filter.accounting_response: --> (3) [attr_filter.accounting_response] = noop (3) } # accounting = ok (3) Sent Accounting-Response Id 85 from 193.136.188.36:1813 to 95.94.70.135:44306 length 20 (3) Finished request Waking up in 0.3 seconds. (4) Received Accounting-Request Id 88 from 95.94.70.135:44306 to 193.136.188.36:1813 length 60 (4) User-Name = 'rffro@isla.pt' (4) Calling-Station-Id = '11:11:11:11:11:11' (4) Acct-Status-Type = Stop (4) # Executing section preacct from file /etc/freeradius/sites-enabled/default (4) preacct { (4) update request { (4) EXPAND %{expr: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0}} (4) --> 1420239171 (4) FreeRADIUS-Acct-Session-Start-Time = "Jan 2 2015 22:52:51 WET" (4) } # update request = noop (4) if (!Event-TimeStamp) { (4) if (!Event-TimeStamp) -> TRUE (4) if (!Event-TimeStamp) { (4) update request { (4) EXPAND %l (4) --> 1420239171 (4) Event-Timestamp := "Jan 2 2015 22:52:51 WET" (4) } # update request = noop (4) } # if (!Event-TimeStamp) = noop (4) policy acct_unique { (4) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) { (4) EXPAND %{string:Class} (4) --> (4) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) -> FALSE (4) else { (4) update request { (4) EXPAND %{md5:%{User-Name},%{Acct-Session-ID},%{%{NAS-IPv6-Address}:-%{NAS-IP-Address}},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}} (4) --> 06dc868691ae159ec1f9a619002b6638 (4) &Acct-Unique-Session-Id := "06dc868691ae159ec1f9a619002b6638" (4) } # update request = noop (4) } # else = noop (4) } # policy acct_unique = noop (4) suffix: Checking for suffix after "@" (4) suffix: Looking up realm "isla.pt" for User-Name = "rffro@isla.pt" Segmentation fault (core dumped)

radius2:/tmp# gdb /usr/sbin/freeradius core GNU gdb (Debian 7.7.1+dfsg-5) 7.7.1 Copyright (C) 2014 Free Software Foundation, Inc. License GPLv3+: GNU GPL version 3 or later http://gnu.org/licenses/gpl.html This is free software: you are free to change and redistribute it. There is NO WARRANTY, to the extent permitted by law. Type "show copying" and "show warranty" for details. This GDB was configured as "x86_64-linux-gnu". Type "show configuration" for configuration details. For bug reporting instructions, please see: http://www.gnu.org/software/gdb/bugs/. Find the GDB manual and other documentation resources online at: http://www.gnu.org/software/gdb/documentation/. For help, type "help". Type "apropos word" to search for commands related to "word"... Reading symbols from /usr/sbin/freeradius...(no debugging symbols found)...done. [New LWP 23108] [Thread debugging using libthread_db enabled] Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1". Core was generated by `freeradius -X'. Program terminated with signal SIGSEGV, Segmentation fault.

0 0x00007f9b280b55fa in regex_exec ()

from /usr/lib/freeradius/libfreeradius-radius.so (gdb) info threads Id Target Id Frame

Thread 1 (Thread 0x7f9b28713740 (LWP 23108)):

0 0x00007f9b280b55fa in regex_exec ()

from /usr/lib/freeradius/libfreeradius-radius.so No symbol table info available.

1 0x0000000000445da1 in realm_find ()

No symbol table info available.

2 0x00007f9b1bdfdfce in ?? () from /usr/lib/freeradius/rlm_realm.so

No symbol table info available.

3 0x00007f9b1bdfe6dc in ?? () from /usr/lib/freeradius/rlm_realm.so

No symbol table info available.

4 0x0000000000424dde in ?? ()

No symbol table info available.

5 0x00000000004253f8 in ?? ()

No symbol table info available.

6 0x0000000000424f9f in ?? ()

No symbol table info available.

7 0x0000000000425c6d in ?? ()

No symbol table info available.

8 0x0000000000426833 in modcall ()

No symbol table info available.

9 0x00000000004225b2 in indexed_modcall ()

No symbol table info available.

10 0x000000000042468c in module_preacct ()

No symbol table info available.

11 0x000000000040db7d in rad_accounting ()

No symbol table info available.

12 0x0000000000438e45 in ?? ()

No symbol table info available.

13 0x0000000000437da2 in ?? ()

No symbol table info available.

14 0x000000000043965c in request_receive ()

No symbol table info available. ---Type to continue, or q to quit---

15 0x000000000041666b in ?? ()

No symbol table info available.

16 0x000000000043fafb in ?? ()

No symbol table info available.

17 0x00007f9b280bd717 in fr_event_loop ()

from /usr/lib/freeradius/libfreeradius-radius.so No symbol table info available.

18 0x0000000000441543 in radius_event_process ()

No symbol table info available.

19 0x000000000042c674 in main ()

No symbol table info available. (gdb)

radius2:~$ freeradius -xv Fri Jan 2 23:05:49 2015 : Info: freeradius: FreeRADIUS Version 3.0.6, for host x86_64-pc-linux-gnu, built on Jan 2 2015 at 22:41:18 Fri Jan 2 23:05:49 2015 : Debug: Server was built with: Fri Jan 2 23:05:49 2015 : Debug: accounting Fri Jan 2 23:05:49 2015 : Debug: authentication Fri Jan 2 23:05:49 2015 : Debug: ascend binary attributes Fri Jan 2 23:05:49 2015 : Debug: coa Fri Jan 2 23:05:49 2015 : Debug: control-socket Fri Jan 2 23:05:49 2015 : Debug: detail Fri Jan 2 23:05:49 2015 : Debug: dhcp Fri Jan 2 23:05:49 2015 : Debug: dynamic clients Fri Jan 2 23:05:49 2015 : Debug: proxy Fri Jan 2 23:05:49 2015 : Debug: regex-posix-extended Fri Jan 2 23:05:49 2015 : Debug: session-management Fri Jan 2 23:05:49 2015 : Debug: stats Fri Jan 2 23:05:49 2015 : Debug: tcp Fri Jan 2 23:05:49 2015 : Debug: threads Fri Jan 2 23:05:49 2015 : Debug: tls Fri Jan 2 23:05:49 2015 : Debug: unlang Fri Jan 2 23:05:49 2015 : Debug: vmps Fri Jan 2 23:05:49 2015 : Debug: developer Fri Jan 2 23:05:49 2015 : Debug: Server core libs: Fri Jan 2 23:05:49 2015 : Debug: talloc : 2.0.* Fri Jan 2 23:05:49 2015 : Debug: ssl : OpenSSL 1.0.1j 15 Oct 2014 0x100010af (1.0.1j release) Fri Jan 2 23:05:49 2015 : Debug: Library magic number: Fri Jan 2 23:05:49 2015 : Debug: 0xf403000600000000 Fri Jan 2 23:05:49 2015 : Debug: Endianess: Fri Jan 2 23:05:49 2015 : Debug: little Fri Jan 2 23:05:49 2015 : Debug: Compilation flags: Fri Jan 2 23:05:49 2015 : Info: Copyright (C) 1999-2014 The FreeRADIUS server project and contributors Fri Jan 2 23:05:49 2015 : Info: There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A Fri Jan 2 23:05:49 2015 : Info: PARTICULAR PURPOSE Fri Jan 2 23:05:49 2015 : Info: You may redistribute copies of FreeRADIUS under the terms of the Fri Jan 2 23:05:49 2015 : Info: GNU General Public License Fri Jan 2 23:05:49 2015 : Info: For more information about these matters, see the file named COPYRIGHT

ruyrybeyro commented 9 years ago

Hi Alan, it is still crashing. Will send the debug info later on.

On 3 January 2015 at 01:23, Alan DeKok notifications@github.com wrote:

Closed #868 https://github.com/FreeRADIUS/freeradius-server/issues/868 via 74a5f97 https://github.com/FreeRADIUS/freeradius-server/commit/74a5f97fe34ce5d6954dadb59bdc75010a764b0d .

— Reply to this email directly or view it on GitHub https://github.com/FreeRADIUS/freeradius-server/issues/868#event-213613614 .

Regards,

Rui Ribeiro Senior Sysadm ISCTE-IUL https://www.linkedin.com/pub/rui-ribeiro/16/ab8/434

ruyrybeyro commented 9 years ago

This time I pulled from git, not from the 3.0.6 tar.

same situation, crash with the same info with freeradius -X.

new valgrind here http://iscte.pt/~rffro/valgrind.txt

gdb core log

radius2:/tmp# cat gdb-radiusd.log Id Target Id Frame

Thread 1 (Thread 0x7f3c1abdf740 (LWP 6499)):

0 0x00007f3c1a580630 in regex_exec ()

from /usr/lib/freeradius/libfreeradius-radius.so No symbol table info available.

1 0x00000000004469d0 in realm_find ()

No symbol table info available.

2 0x00007f3c122fbfce in ?? () from /usr/lib/freeradius/rlm_realm.so

No symbol table info available.

3 0x00007f3c122fc6dc in ?? () from /usr/lib/freeradius/rlm_realm.so

No symbol table info available.

4 0x0000000000425441 in ?? ()

No symbol table info available.

5 0x0000000000425a8b in ?? ()

No symbol table info available.

6 0x0000000000425602 in ?? ()

No symbol table info available.

7 0x0000000000426300 in ?? ()

No symbol table info available.

8 0x0000000000426ed7 in modcall ()

No symbol table info available.

9 0x0000000000422c15 in indexed_modcall ()

No symbol table info available.

10 0x0000000000424cef in module_preacct ()

No symbol table info available.

11 0x000000000040de9d in rad_accounting ()

No symbol table info available.

12 0x0000000000439618 in ?? ()

No symbol table info available.

13 0x00000000004384e6 in ?? ()

No symbol table info available.

14 0x0000000000439e2f in request_receive ()

No symbol table info available.

15 0x000000000041694c in ?? ()

No symbol table info available.

16 0x0000000000440319 in ?? ()

No symbol table info available.

17 0x00007f3c1a588684 in fr_event_loop ()

from /usr/lib/freeradius/libfreeradius-radius.so No symbol table info available.

18 0x0000000000441d89 in radius_event_process ()

No symbol table info available.

19 0x000000000042cd1d in main ()

No symbol table info available. radius2:/tmp#

alandekok commented 9 years ago

On Jan 3, 2015, at 2:58 AM, ruyrybeyro notifications@github.com wrote:

This time I pulled from git, not from the 3.0.6 tar.

You’re running the “master” branch. Please use the v3.0.6 branch.

And please build with debugging symbols. Otherwise, the backtraces are pretty much useless. They say which function crashed, but not where in that function the problem lies.

It would also help to submit a sample configuration and accounting packet which causes this problem. It doesn’t have to be an entire configuration directory. Just a “realm” configuration should be enough. That will help us reproduce the problem, which means we can fix it.=

ruyrybeyro commented 9 years ago

Thanks for the heads up, had a typo on the git checkout script, now I am running the correct branch. It still crashes. Will send more details later on.

arr2036 commented 9 years ago

Could you try with the code I pushed.

ruyrybeyro commented 9 years ago

Very good news, it does not crash anymore. Whilst before it crashed, now it says "No such realm"

suffix: Checking for suffix after "@" (1) suffix: Looking up realm "isla.pt" for User-Name = "rui@isla.pt" (1) suffix: No such realm "isla.pt"

arr2036 commented 9 years ago

I don't see isla.pt in your list of configured realms?

realm iscte.pt {
nostrip
authhost = LOCAL
accthost = LOCAL
}
realm ~..intranet$ {
}
realm ~..intra$ {
}
realm ~..iscte-iul.pt$ {
}
realm myabc.com {
}
realm ~.3gppnetwork.org$ {
}
realm LOCAL {
}
realm NULL {
}
home_server_pool EDUROAM {
type = fail-over
home_server = cv-radius
home_server = cv2-radius
}
realm ~.@~.* {
pool = EDUROAM
nostrip
}
realm TO_EDUROAM {
pool = EDUROAM
nostrip
}
arr2036 commented 9 years ago

Testing with 

realm ~..intra$ {
}

Gives expected results:

(1) Received Access-Request Id 251 from 127.0.0.1:54201 to 127.0.0.1:1812 length 81
(1)   User-Name = 'foo@bbintra'
(1)   User-Password = 'bar'
(1)   NAS-IP-Address = 127.0.0.1
(1)   NAS-Port = 0
(1)   Message-Authenticator = 0xdb7359927c17e9c46db471af42c77cd3
(1) # Executing section authorize from file /usr/local/freeradius/etc/raddb/sites-enabled/default
(1)   authorize {
(1) suffix: Checking for suffix after "@"
(1) suffix: Looking up realm "bbintra" for User-Name = "foo@bbintra"
(1) suffix: Found realm "~..intra$"
(1) suffix: Adding Stripped-User-Name = "foo"
(1) suffix: Adding Realm = "bbintra"
(1) suffix: Authentication realm is LOCAL

That's with regex-posix, but it should be identical to regex-posix-extended for simple expressions.

Regarding the crashing that's pretty bad behaviour from regexec, even with an invalid flag it shouldn't just SEGV.

ruyrybeyro commented 9 years ago

Exactly, isla.pt is not my realm, it was my test case. The bug was in roaming, I made up an accounting stop message for the test case with a fictitious user. It seemed good enough for the test case, as it crashed the server. Thanks and happy new year.

arr2036 commented 9 years ago

Ah fair enough, thanks for confirming it's fixed.

ruyrybeyro commented 9 years ago

I will leave here what I used to build the packet to crash it. fr3_bug_1 fr3_bug_2