- Freeradius-Users - lists.freeradius.org

SASL AuthN to LDAP
by Brendan Kearney 19 Oct '16

19 Oct '16

i am trying to use a Kerberos keytab file to authenticate to LDAP. the keytab file is the same one used to authenticate users against the Kerberos database. the principal in the keytab has been mapped to an object in LDAP, for access to be granted. i dont seem to be getting the configs correct for the LDAP binds to work. can you shed light on what i am missing? i am setting KRB5_CLIENT_KTNAME = '/etc/raddb/radius.keytab' in the sasl {} stanzas in mods-available/ldap, which is linked to mods-enabled/. the radiusd -X output below indicates that anonymous binds are being attempted. this seems to indicate the keytab is not being picked up and the identity is not being found. i can run a 'kinit -kt /etc/raddb/radius.keytab' and get a TGT back. i can also run 'ldapwhoami' with that TGT and get the mapped LDAP identity back. am i going about setting the KRB5_CLIENT_KTNAME wrong? freeradius version 3.0.10 (packaged for fedora 24) Copyright (C) 1999-2015 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/raddb/dictionary including configuration file /etc/raddb/radiusd.conf including configuration file /etc/raddb/clients.conf including files in directory /etc/raddb/mods-enabled/ including configuration file /etc/raddb/mods-enabled/always including configuration file /etc/raddb/mods-enabled/attr_filter including configuration file /etc/raddb/mods-enabled/cache_eap including configuration file /etc/raddb/mods-enabled/chap including configuration file /etc/raddb/mods-enabled/detail including configuration file /etc/raddb/mods-enabled/detail.log including configuration file /etc/raddb/mods-enabled/dhcp including configuration file /etc/raddb/mods-enabled/digest including configuration file /etc/raddb/mods-enabled/dynamic_clients including configuration file /etc/raddb/mods-enabled/eap including configuration file /etc/raddb/mods-enabled/echo including configuration file /etc/raddb/mods-enabled/exec including configuration file /etc/raddb/mods-enabled/expiration including configuration file /etc/raddb/mods-enabled/expr including configuration file /etc/raddb/mods-enabled/files including configuration file /etc/raddb/mods-enabled/linelog including configuration file /etc/raddb/mods-enabled/logintime including configuration file /etc/raddb/mods-enabled/mschap including configuration file /etc/raddb/mods-enabled/ntlm_auth including configuration file /etc/raddb/mods-enabled/pap including configuration file /etc/raddb/mods-enabled/passwd including configuration file /etc/raddb/mods-enabled/preprocess including configuration file /etc/raddb/mods-enabled/radutmp including configuration file /etc/raddb/mods-enabled/realm including configuration file /etc/raddb/mods-enabled/replicate including configuration file /etc/raddb/mods-enabled/soh including configuration file /etc/raddb/mods-enabled/sradutmp including configuration file /etc/raddb/mods-enabled/unix including configuration file /etc/raddb/mods-enabled/unpack including configuration file /etc/raddb/mods-enabled/utf8 including configuration file /etc/raddb/mods-enabled/krb5 including configuration file /etc/raddb/mods-enabled/ldap including configuration file /etc/raddb/mods-enabled/sql including configuration file /etc/raddb/mods-config/sql/main/mysql/queries.conf including files in directory /etc/raddb/policy.d/ including configuration file /etc/raddb/policy.d/accounting including configuration file /etc/raddb/policy.d/control including configuration file /etc/raddb/policy.d/cui including configuration file /etc/raddb/policy.d/debug including configuration file /etc/raddb/policy.d/dhcp including configuration file /etc/raddb/policy.d/eap including configuration file /etc/raddb/policy.d/filter including configuration file /etc/raddb/policy.d/operator-name including configuration file /etc/raddb/policy.d/canonicalization.orig including configuration file /etc/raddb/policy.d/canonicalization including files in directory /etc/raddb/sites-enabled/ including configuration file /etc/raddb/sites-enabled/default including configuration file /etc/raddb/sites-enabled/inner-tunnel main { security { user = "radiusd" group = "radiusd" allow_core_dumps = no } name = "radiusd" prefix = "/usr" localstatedir = "/var" logdir = "/var/log/radius" run_dir = "/var/run/radiusd" } main { name = "radiusd" prefix = "/usr" localstatedir = "/var" sbindir = "/usr/sbin" logdir = "/var/log/radius" run_dir = "/var/run/radiusd" libdir = "/usr/lib64/freeradius" radacctdir = "/var/log/radius/radacct" hostname_lookups = no max_request_time = 30 cleanup_delay = 5 max_requests = 1024 pidfile = "/var/run/radiusd/radiusd.pid" checkrad = "/usr/sbin/checkrad" debug_level = 0 proxy_requests = no 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 #### 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 } } Debugger not attached # Creating Auth-Type = digest # Creating Auth-Type = LDAP radiusd: #### Instantiating modules #### # Loaded module rlm_always # Loading module "reject" from file /etc/raddb/mods-enabled/always always reject { rcode = "reject" simulcount = 0 mpp = no } # Loading module "fail" from file /etc/raddb/mods-enabled/always always fail { rcode = "fail" simulcount = 0 mpp = no } # Loading module "ok" from file /etc/raddb/mods-enabled/always always ok { rcode = "ok" simulcount = 0 mpp = no } # Loading module "handled" from file /etc/raddb/mods-enabled/always always handled { rcode = "handled" simulcount = 0 mpp = no } # Loading module "invalid" from file /etc/raddb/mods-enabled/always always invalid { rcode = "invalid" simulcount = 0 mpp = no } # Loading module "userlock" from file /etc/raddb/mods-enabled/always always userlock { rcode = "userlock" simulcount = 0 mpp = no } # Loading module "notfound" from file /etc/raddb/mods-enabled/always always notfound { rcode = "notfound" simulcount = 0 mpp = no } # Loading module "noop" from file /etc/raddb/mods-enabled/always always noop { rcode = "noop" simulcount = 0 mpp = no } # Loading module "updated" from file /etc/raddb/mods-enabled/always always updated { rcode = "updated" simulcount = 0 mpp = no } # Loaded module rlm_attr_filter # Loading module "attr_filter.post-proxy" from file /etc/raddb/mods-enabled/attr_filter attr_filter attr_filter.post-proxy { filename = "/etc/raddb/mods-config/attr_filter/post-proxy" key = "%{Realm}" relaxed = no } # Loading module "attr_filter.pre-proxy" from file /etc/raddb/mods-enabled/attr_filter attr_filter attr_filter.pre-proxy { filename = "/etc/raddb/mods-config/attr_filter/pre-proxy" key = "%{Realm}" relaxed = no } # Loading module "attr_filter.access_reject" from file /etc/raddb/mods-enabled/attr_filter attr_filter attr_filter.access_reject { filename = "/etc/raddb/mods-config/attr_filter/access_reject" key = "%{User-Name}" relaxed = no } # Loading module "attr_filter.access_challenge" from file /etc/raddb/mods-enabled/attr_filter attr_filter attr_filter.access_challenge { filename = "/etc/raddb/mods-config/attr_filter/access_challenge" key = "%{User-Name}" relaxed = no } # Loading module "attr_filter.accounting_response" from file /etc/raddb/mods-enabled/attr_filter attr_filter attr_filter.accounting_response { filename = "/etc/raddb/mods-config/attr_filter/accounting_response" key = "%{User-Name}" relaxed = no } # Loaded module rlm_cache # Loading module "cache_eap" from file /etc/raddb/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_chap # Loading module "chap" from file /etc/raddb/mods-enabled/chap # Loaded module rlm_detail # Loading module "detail" from file /etc/raddb/mods-enabled/detail detail { filename = "/var/log/radius/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 } # Loading module "auth_log" from file /etc/raddb/mods-enabled/detail.log detail auth_log { filename = "/var/log/radius/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/raddb/mods-enabled/detail.log detail reply_log { filename = "/var/log/radius/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/raddb/mods-enabled/detail.log detail pre_proxy_log { filename = "/var/log/radius/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/raddb/mods-enabled/detail.log detail post_proxy_log { filename = "/var/log/radius/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_dhcp # Loading module "dhcp" from file /etc/raddb/mods-enabled/dhcp # Loaded module rlm_digest # Loading module "digest" from file /etc/raddb/mods-enabled/digest # Loaded module rlm_dynamic_clients # Loading module "dynamic_clients" from file /etc/raddb/mods-enabled/dynamic_clients # Loaded module rlm_eap # Loading module "eap" from file /etc/raddb/mods-enabled/eap eap { default_eap_type = "md5" timer_expire = 60 ignore_unknown_eap_types = no cisco_accounting_username_bug = no max_sessions = 1024 } # Loaded module rlm_exec # Loading module "echo" from file /etc/raddb/mods-enabled/echo exec echo { wait = yes program = "/bin/echo %{User-Name}" input_pairs = "request" output_pairs = "reply" shell_escape = yes } # Loading module "exec" from file /etc/raddb/mods-enabled/exec exec { wait = no input_pairs = "request" shell_escape = yes timeout = 10 } # Loaded module rlm_expiration # Loading module "expiration" from file /etc/raddb/mods-enabled/expiration # Loaded module rlm_expr # Loading module "expr" from file /etc/raddb/mods-enabled/expr expr { safe_characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /äéöüàâæçèéêëîïôœùûüaÿÄÉÖÜßÀÂÆÇÈÉÊËÎÏÔŒÙÛÜŸ" } # Loaded module rlm_files # Loading module "files" from file /etc/raddb/mods-enabled/files files { filename = "/etc/raddb/mods-config/files/authorize" acctusersfile = "/etc/raddb/mods-config/files/accounting" preproxy_usersfile = "/etc/raddb/mods-config/files/pre-proxy" } # Loaded module rlm_linelog # Loading module "linelog" from file /etc/raddb/mods-enabled/linelog linelog { filename = "/var/log/radius/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/raddb/mods-enabled/linelog linelog log_accounting { filename = "/var/log/radius/linelog-accounting" escape_filenames = no syslog_severity = "info" permissions = 384 format = "" reference = "Accounting-Request.%{%{Acct-Status-Type}:-unknown}" } # Loaded module rlm_logintime # Loading module "logintime" from file /etc/raddb/mods-enabled/logintime logintime { minimum_timeout = 60 } # Loaded module rlm_mschap # Loading module "mschap" from file /etc/raddb/mods-enabled/mschap mschap { use_mppe = no require_encryption = yes require_strong = yes with_ntdomain_hack = yes passchange { } allow_retry = yes } # Loading module "ntlm_auth" from file /etc/raddb/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_pap # Loading module "pap" from file /etc/raddb/mods-enabled/pap pap { normalise = yes } # Loaded module rlm_passwd # Loading module "etc_passwd" from file /etc/raddb/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_preprocess # Loading module "preprocess" from file /etc/raddb/mods-enabled/preprocess preprocess { huntgroups = "/etc/raddb/mods-config/preprocess/huntgroups" hints = "/etc/raddb/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_radutmp # Loading module "radutmp" from file /etc/raddb/mods-enabled/radutmp radutmp { filename = "/var/log/radius/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/raddb/mods-enabled/realm realm IPASS { format = "prefix" delimiter = "/" ignore_default = no ignore_null = no } # Loading module "suffix" from file /etc/raddb/mods-enabled/realm realm suffix { format = "suffix" delimiter = "@" ignore_default = no ignore_null = no } # Loading module "realmpercent" from file /etc/raddb/mods-enabled/realm realm realmpercent { format = "suffix" delimiter = "%" ignore_default = no ignore_null = no } # Loading module "ntdomain" from file /etc/raddb/mods-enabled/realm realm ntdomain { format = "prefix" delimiter = "\" ignore_default = no ignore_null = no } # Loaded module rlm_replicate # Loading module "replicate" from file /etc/raddb/mods-enabled/replicate # Loaded module rlm_soh # Loading module "soh" from file /etc/raddb/mods-enabled/soh soh { dhcp = yes } # Loading module "sradutmp" from file /etc/raddb/mods-enabled/sradutmp radutmp sradutmp { filename = "/var/log/radius/sradutmp" username = "%{User-Name}" case_sensitive = yes check_with_nas = yes permissions = 420 caller_id = no } # Loaded module rlm_unix # Loading module "unix" from file /etc/raddb/mods-enabled/unix unix { radwtmp = "/var/log/radius/radwtmp" } Creating attribute Unix-Group # Loaded module rlm_unpack # Loading module "unpack" from file /etc/raddb/mods-enabled/unpack # Loaded module rlm_utf8 # Loading module "utf8" from file /etc/raddb/mods-enabled/utf8 # Loaded module rlm_krb5 # Loading module "krb5" from file /etc/raddb/mods-enabled/krb5 krb5 { keytab = "/etc/raddb/radius.keytab" service_principal = "radius/server1.bpk2.com" } # Loaded module rlm_ldap # Loading module "ldap" from file /etc/raddb/mods-enabled/ldap ldap { server = "server1.bpk2.com" sasl { mech = "GSSAPI" realm = "BPK2.COM" } read_clients = yes user { scope = "sub" access_positive = yes sasl { } } group { filter = "(objectClass=posixGroup)" scope = "sub" name_attribute = "cn" membership_attribute = "memberOf" cacheable_name = no cacheable_dn = no } client { filter = "(objectClass=radiusClient)" scope = "sub" base_dn = "dc=bpk2,dc=com" } profile { } options { ldap_debug = 40 chase_referrals = yes rebind = yes net_timeout = 1 res_timeout = 10 srv_timelimit = 3 idle = 60 probes = 3 interval = 3 } tls { start_tls = no } } Creating attribute LDAP-Group # Loaded module rlm_sql # Loading module "sql" from file /etc/raddb/mods-enabled/sql sql { driver = "rlm_sql_mysql" server = "database.bpk2.com" port = 3306 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_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.-_: /" 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-ID}:-%{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}:-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 = FROM_UNIXTIME(%{integer:Event-Timestamp}), 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_mysql (module rlm_sql_mysql) loaded and linked Creating attribute SQL-Group instantiate { } modules { # Instantiating module "reject" from file /etc/raddb/mods-enabled/always # Instantiating module "fail" from file /etc/raddb/mods-enabled/always # Instantiating module "ok" from file /etc/raddb/mods-enabled/always # Instantiating module "handled" from file /etc/raddb/mods-enabled/always # Instantiating module "invalid" from file /etc/raddb/mods-enabled/always # Instantiating module "userlock" from file /etc/raddb/mods-enabled/always # Instantiating module "notfound" from file /etc/raddb/mods-enabled/always # Instantiating module "noop" from file /etc/raddb/mods-enabled/always # Instantiating module "updated" from file /etc/raddb/mods-enabled/always # Instantiating module "attr_filter.post-proxy" from file /etc/raddb/mods-enabled/attr_filter reading pairlist file /etc/raddb/mods-config/attr_filter/post-proxy # Instantiating module "attr_filter.pre-proxy" from file /etc/raddb/mods-enabled/attr_filter reading pairlist file /etc/raddb/mods-config/attr_filter/pre-proxy # Instantiating module "attr_filter.access_reject" from file /etc/raddb/mods-enabled/attr_filter reading pairlist file /etc/raddb/mods-config/attr_filter/access_reject [/etc/raddb/mods-config/attr_filter/access_reject]:11 Check item "FreeRADIUS-Response-Delay" found in filter list for realm "DEFAULT". [/etc/raddb/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/raddb/mods-enabled/attr_filter reading pairlist file /etc/raddb/mods-config/attr_filter/access_challenge # Instantiating module "attr_filter.accounting_response" from file /etc/raddb/mods-enabled/attr_filter reading pairlist file /etc/raddb/mods-config/attr_filter/accounting_response # Instantiating module "cache_eap" from file /etc/raddb/mods-enabled/cache_eap rlm_cache (cache_eap): Driver rlm_cache_rbtree (module rlm_cache_rbtree) loaded and linked # Instantiating module "detail" from file /etc/raddb/mods-enabled/detail # Instantiating module "auth_log" from file /etc/raddb/mods-enabled/detail.log rlm_detail (auth_log): 'User-Password' suppressed, will not appear in detail output # Instantiating module "reply_log" from file /etc/raddb/mods-enabled/detail.log # Instantiating module "pre_proxy_log" from file /etc/raddb/mods-enabled/detail.log # Instantiating module "post_proxy_log" from file /etc/raddb/mods-enabled/detail.log # Instantiating module "eap" from file /etc/raddb/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 { rsa_key_exchange = no dh_key_exchange = yes rsa_key_length = 512 dh_key_length = 512 verify_depth = 0 ca_path = "/etc/raddb/certs" pem_file_type = yes private_key_file = "/etc/raddb/certs/server.pem" certificate_file = "/etc/raddb/certs/server.pem" ca_file = "/etc/raddb/certs/ca.pem" private_key_password = <<< secret >>> dh_file = "/etc/raddb/certs/dh" fragment_size = 1024 include_length = yes check_crl = no check_all_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_ttls ttls { tls = "tls-common" default_eap_type = "md5" copy_request_to_tunnel = yes use_tunneled_reply = yes 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 "expiration" from file /etc/raddb/mods-enabled/expiration # Instantiating module "files" from file /etc/raddb/mods-enabled/files reading pairlist file /etc/raddb/mods-config/files/authorize reading pairlist file /etc/raddb/mods-config/files/accounting reading pairlist file /etc/raddb/mods-config/files/pre-proxy # Instantiating module "linelog" from file /etc/raddb/mods-enabled/linelog # Instantiating module "log_accounting" from file /etc/raddb/mods-enabled/linelog # Instantiating module "logintime" from file /etc/raddb/mods-enabled/logintime # Instantiating module "mschap" from file /etc/raddb/mods-enabled/mschap rlm_mschap (mschap): using internal authentication # Instantiating module "pap" from file /etc/raddb/mods-enabled/pap # Instantiating module "etc_passwd" from file /etc/raddb/mods-enabled/passwd rlm_passwd: nfields: 3 keyfield 0(User-Name) listable: no # Instantiating module "preprocess" from file /etc/raddb/mods-enabled/preprocess reading pairlist file /etc/raddb/mods-config/preprocess/huntgroups reading pairlist file /etc/raddb/mods-config/preprocess/hints # Instantiating module "IPASS" from file /etc/raddb/mods-enabled/realm # Instantiating module "suffix" from file /etc/raddb/mods-enabled/realm # Instantiating module "realmpercent" from file /etc/raddb/mods-enabled/realm # Instantiating module "ntdomain" from file /etc/raddb/mods-enabled/realm # Instantiating module "krb5" from file /etc/raddb/mods-enabled/krb5 Using MIT Kerberos library rlm_krb5 (krb5): Using service principal "radius/server1.bpk2.com@" rlm_krb5 (krb5): Using keytab "FILE:/etc/raddb/radius.keytab" rlm_krb5 (krb5): Initialising connection pool pool { start = 10 min = 4 max = 10 spare = 3 uses = 0 lifetime = 0 cleanup_interval = 30 idle_timeout = 60 retry_delay = 1 spread = no } rlm_krb5 (krb5): Opening additional connection (0), 1 of 10 pending slots used rlm_krb5 (krb5): Opening additional connection (1), 1 of 9 pending slots used rlm_krb5 (krb5): Opening additional connection (2), 1 of 8 pending slots used rlm_krb5 (krb5): Opening additional connection (3), 1 of 7 pending slots used rlm_krb5 (krb5): Opening additional connection (4), 1 of 6 pending slots used rlm_krb5 (krb5): Opening additional connection (5), 1 of 5 pending slots used rlm_krb5 (krb5): Opening additional connection (6), 1 of 4 pending slots used rlm_krb5 (krb5): Opening additional connection (7), 1 of 3 pending slots used rlm_krb5 (krb5): Opening additional connection (8), 1 of 2 pending slots used rlm_krb5 (krb5): Opening additional connection (9), 1 of 1 pending slots used # Instantiating module "ldap" from file /etc/raddb/mods-enabled/ldap rlm_ldap: libldap vendor: OpenLDAP, version: 20444 accounting { reference = "%{tolower:type.%{Acct-Status-Type}}" } post-auth { reference = "." } rlm_ldap (ldap): 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_ldap (ldap): Opening additional connection (0), 1 of 32 pending slots used rlm_ldap (ldap): Connecting to ldap://server1.bpk2.com:389 rlm_ldap (ldap): Starting SASL mech(s): GSSAPI SASL/GSSAPI authentication started rlm_ldap (ldap): Bind with (anonymous) to ldap://server1.bpk2.com:389 failed: Local error rlm_ldap (ldap): Opening connection failed (0) rlm_ldap (ldap): Removing connection pool /etc/raddb/mods-enabled/ldap[8]: Instantiation failed for module "ldap"

4 11

Deploying EAP-TTLS WLAN profile to Android devices.
by Bogdan Rudas 19 Oct '16

19 Oct '16

Hello all, Are there any convenient way to deploy 801.1x WiFi profile and CA certificate to Android device? I have checked Google MDM but it don't allows unattended CA installation to regular devices. I'm sorry if this message will be considered offtopic here. Thank you. -- Bogdan Rudas Head of Minsk IT Support Department Exadel Inc. http://www.exadel.com/ E-mail: brudas(a)exadel.com Skype ID: bogdan.rudas -- CONFIDENTIALITY NOTICE: This email and files attached to it are confidential. If you are not the intended recipient you are hereby notified that using, copying, distributing or taking any action in reliance on the contents of this information is strictly prohibited. If you have received this email in error please notify the sender and delete this email.

3 2

Re: Aw: Attributes from users File not added to Proxy Response
by Stefan Paetow 19 Oct '16

19 Oct '16

>Not anyone had an idea about this request??? AFAIK the users file is only invoked when you are actually the authentication end-point. If you're proxying, this does not happen. Use unlang in the post-proxy section to add the attribute manually. And finally, *do* upgrade. 2.2.8 is DEAD, even if it's the last version available for Ubuntu. You can spin your own by following the Debian instructions on the FreeRADIUS Wiki. Stefan Paetow Moonshot Industry & Research Liaison Coordinator t: +44 (0)1235 822 125 gpg: 0x3FCE5142 xmpp: stefanp(a)jabber.dev.ja.net skype: stefan.paetow.janet jisc.ac.uk Jisc is a registered charity (number 1149740) and a company limited by guarantee which is registered in England under Company No. 5747339, VAT No. GB 197 0632 86. Jisc¹s registered office is: One Castlepark, Tower Hill, Bristol, BS2 0JA. T 0203 697 5800. >

1 0

Aw: Attributes from users File not added to Proxy Response
by Dr. Karl-Heinz Pape 19 Oct '16

19 Oct '16

Hello! Not anyone had an idea about this request??? dk8hi wrote: > Message: 1 > Date: Tue, 11 Oct 2016 09:21:17 +0200 > From: "Dr. Karl-Heinz Pape" <dk8hi(a)web.de> > To: freeradius-users(a)lists.freeradius.org > Subject: Attributes from users File not added to Proxy Response > Message-ID: > <trinity-537189d4-54f2-4aca-b1d7-817543ecd3cd-1476170477506@3capp-webde-bap42> > > Content-Type: text/plain; charset="UTF-8" > > Hello! > I am running FreeRADIUS Version 2.2.8 (the latest version available for > my current Ubuntu set-up). > The FreeRADIUS acts as a proxy and forwards the request to another > RADIUS. > The answer is received and the information in the user file seems to be > processed > (which can be seen from the double Auth-Type listed in the debug > output, and yes, > I removed the Auth-Type from the users file and it still does not > work). > Now the additional attributes from the users file are NOT added to the > response of the FreeRADIUS > to the NAS. > With an earlier version of FreeRADIUS these attributes had been added, > as I can see from old > Wireshark dumps of the RADIUS communication. > The Context-Name = dsl would be required by the RedBack NAS to find the > correct context! > Am I missing something? > Thanks in advance > Karl-Heinz Please see my original request in: Freeradius-Users Digest, Vol 138, Issue 23 *************************************************

2 1

Long delay on response to PPPoE NAS (Mikrotik) on FreeRadius 3.0.12 + MySQL
by Nataniel Klug 18 Oct '16

18 Oct '16

Hello, I am trying to upgrade my FreeRadius servers to version 3.0.12. We are making some changes in the structure of the company and this is going to be needed. Today I run FreeRadius 2.1.10 and I make my check and accounting on MySQL and IPPool on PostgreSQL. Now I am changing the structure to FreeRadius 3.0.12 and all check, accounting and ippool going to a MaxScale/MariaDB cluster. I've already tested the MariaDB server and all requests are being replied in 0,006 seconds. It's fast enough right now. I compiled from source FreeRadius 3.0.12 on a Debian 8.6 (Linux HA-Radius-2 3.16.0-4-amd64 #1 SMP Debian 3.16.36-1+deb8u1 (2016-09-03) x86_64 GNU/Linux). The problem is that for some reason FreeRadius is taking a long time to answer to NAS Access-Request and the NAS send a lot of requests to receive an answer. Bellow I show a FreeRadius log and later I will explain what I saw in this (for the purpose of this log I disabled SQL IPPool and Simultaneous-Check): Ready to process requests (0) Received Access-Request Id 17 from 187.19.96.40:35728 to 172.31.255.188:1812 length 136 (0) Service-Type = Framed-User (0) Framed-Protocol = PPP (0) NAS-Port = 15728647 (0) NAS-Port-Type = Ethernet (0) User-Name = "teste-sql" (0) Calling-Station-Id = "E4:8D:8C:EC:90:A2" (0) Called-Station-Id = "CSC-755-rt-01" (0) NAS-Port-Id = "vlan14" (0) User-Password = "senha34" (0) NAS-Identifier = "CSC-755-rt-01" (0) NAS-IP-Address = 187.19.96.40 (0) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default (0) authorize { (0) sql: EXPAND %{User-Name} (0) sql: --> teste-sql (0) sql: SQL-User-Name set to 'teste-sql' rlm_sql (sql): Reserved connection (1) (0) sql: EXPAND SELECT id, username, attribute, value, op FROM radcheck WHERE username = '%{SQL-User-Name}' ORDER BY id (0) sql: --> SELECT id, username, attribute, value, op FROM radcheck WHERE username = 'teste-sql' ORDER BY id (0) sql: Executing select query: SELECT id, username, attribute, value, op FROM radcheck WHERE username = 'teste-sql' ORDER BY id (0) sql: User found in radcheck table (0) sql: Conditional check items matched, merging assignment check items (0) sql: Crypt-Password := "w54qGtgpcqSaw" (0) sql: Pool-Name := "main_pool" (0) sql: EXPAND SELECT id, username, attribute, value, op FROM radreply WHERE username = '%{SQL-User-Name}' ORDER BY id (0) sql: --> SELECT id, username, attribute, value, op FROM radreply WHERE username = 'teste-sql' ORDER BY id (0) sql: Executing select query: SELECT id, username, attribute, value, op FROM radreply WHERE username = 'teste-sql' ORDER BY id (0) sql: EXPAND SELECT groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority (0) sql: --> SELECT groupname FROM radusergroup WHERE username = 'teste-sql' ORDER BY priority (0) sql: Executing select query: SELECT groupname FROM radusergroup WHERE username = 'teste-sql' ORDER BY priority (0) sql: User found in the group table (0) sql: EXPAND SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = '%{SQL-Group}' ORDER BY id (0) sql: --> SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = 'grupo-teste-sql' ORDER BY id (0) sql: Executing select query: SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = 'grupo-teste-sql' ORDER BY id (0) sql: Group "grupo-teste-sql": Conditional check items matched (0) sql: Group "grupo-teste-sql": Merging assignment check items (0) sql: Simultaneous-Use := 1 (0) sql: EXPAND SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = '%{SQL-Group}' ORDER BY id (0) sql: --> SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = 'grupo-teste-sql' ORDER BY id (0) sql: Executing select query: SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = 'grupo-teste-sql' ORDER BY id (0) sql: Group "grupo-teste-sql": Merging reply items (0) sql: Mikrotik-Rate-Limit := "32k" rlm_sql (sql): Released connection (1) rlm_sql (sql): Closing connection (2), from 10 unused connections rlm_sql_mysql: Socket destructor called, closing socket (0) [sql] = ok (0) [pap] = updated (0) } # authorize = updated (0) Found Auth-Type = PAP (0) # Executing group from file /usr/local/etc/raddb/sites-enabled/default (0) Auth-Type PAP { (0) pap: Login attempt with password (0) pap: Comparing with "known-good" Crypt-password (0) pap: User authenticated successfully (0) [pap] = ok (0) } # Auth-Type PAP = ok (0) # Executing section session from file /usr/local/etc/raddb/sites-enabled/default (0) session { (0) sql: EXPAND %{User-Name} (0) sql: --> teste-sql (0) sql: SQL-User-Name set to 'teste-sql' (0) sql: EXPAND SELECT COUNT(*) FROM radacct WHERE username = '%{SQL-User-Name}' AND acctstoptime IS NULL (0) sql: --> SELECT COUNT(*) FROM radacct WHERE username = 'teste-sql' AND acctstoptime IS NULL rlm_sql (sql): Reserved connection (3) (0) sql: Executing select query: SELECT COUNT(*) FROM radacct WHERE username = 'teste-sql' AND acctstoptime IS NULL rlm_sql (sql): Released connection (3) (0) [sql] = ok (0) } # session = ok (0) Login OK: [teste-sql] (from client CSC-755-rt-01 port 15728647 cli E4:8D:8C:EC:90:A2) (0) Sent Access-Accept Id 17 from 172.31.255.188:1812 to 187.19.96.40:35728 length 0 (0) Mikrotik-Rate-Limit = "32k" (0) Finished request Waking up in 1.9 seconds. (0) Cleaning up request packet ID 17 with timestamp +47 Ready to process requests (1) Received Access-Request Id 17 from 187.19.96.40:35728 to 172.31.255.188:1812 length 136 (1) Service-Type = Framed-User (1) Framed-Protocol = PPP (1) NAS-Port = 15728647 (1) NAS-Port-Type = Ethernet (1) User-Name = "teste-sql" (1) Calling-Station-Id = "E4:8D:8C:EC:90:A2" (1) Called-Station-Id = "CSC-755-rt-01" (1) NAS-Port-Id = "vlan14" (1) User-Password = "senha34" (1) NAS-Identifier = "CSC-755-rt-01" (1) NAS-IP-Address = 187.19.96.40 (1) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default (1) authorize { (1) sql: EXPAND %{User-Name} (1) sql: --> teste-sql (1) sql: SQL-User-Name set to 'teste-sql' rlm_sql (sql): Reserved connection (4) (1) sql: EXPAND SELECT id, username, attribute, value, op FROM radcheck WHERE username = '%{SQL-User-Name}' ORDER BY id (1) sql: --> SELECT id, username, attribute, value, op FROM radcheck WHERE username = 'teste-sql' ORDER BY id (1) sql: Executing select query: SELECT id, username, attribute, value, op FROM radcheck WHERE username = 'teste-sql' ORDER BY id (1) sql: User found in radcheck table (1) sql: Conditional check items matched, merging assignment check items (1) sql: Crypt-Password := "w54qGtgpcqSaw" (1) sql: Pool-Name := "main_pool" (1) sql: EXPAND SELECT id, username, attribute, value, op FROM radreply WHERE username = '%{SQL-User-Name}' ORDER BY id (1) sql: --> SELECT id, username, attribute, value, op FROM radreply WHERE username = 'teste-sql' ORDER BY id (1) sql: Executing select query: SELECT id, username, attribute, value, op FROM radreply WHERE username = 'teste-sql' ORDER BY id (1) sql: EXPAND SELECT groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority (1) sql: --> SELECT groupname FROM radusergroup WHERE username = 'teste-sql' ORDER BY priority (1) sql: Executing select query: SELECT groupname FROM radusergroup WHERE username = 'teste-sql' ORDER BY priority (1) sql: User found in the group table (1) sql: EXPAND SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = '%{SQL-Group}' ORDER BY id (1) sql: --> SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = 'grupo-teste-sql' ORDER BY id (1) sql: Executing select query: SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = 'grupo-teste-sql' ORDER BY id (1) sql: Group "grupo-teste-sql": Conditional check items matched (1) sql: Group "grupo-teste-sql": Merging assignment check items (1) sql: Simultaneous-Use := 1 (1) sql: EXPAND SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = '%{SQL-Group}' ORDER BY id (1) sql: --> SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = 'grupo-teste-sql' ORDER BY id (1) sql: Executing select query: SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = 'grupo-teste-sql' ORDER BY id (1) sql: Group "grupo-teste-sql": Merging reply items (1) sql: Mikrotik-Rate-Limit := "32k" rlm_sql (sql): Released connection (4) rlm_sql (sql): Closing connection (5), from 9 unused connections rlm_sql_mysql: Socket destructor called, closing socket (1) [sql] = ok (1) [pap] = updated (1) } # authorize = updated (1) Found Auth-Type = PAP (1) # Executing group from file /usr/local/etc/raddb/sites-enabled/default (1) Auth-Type PAP { (1) pap: Login attempt with password (1) pap: Comparing with "known-good" Crypt-password (1) pap: User authenticated successfully (1) [pap] = ok (1) } # Auth-Type PAP = ok (1) # Executing section session from file /usr/local/etc/raddb/sites-enabled/default (1) session { (1) sql: EXPAND %{User-Name} (1) sql: --> teste-sql (1) sql: SQL-User-Name set to 'teste-sql' (1) sql: EXPAND SELECT COUNT(*) FROM radacct WHERE username = '%{SQL-User-Name}' AND acctstoptime IS NULL (1) sql: --> SELECT COUNT(*) FROM radacct WHERE username = 'teste-sql' AND acctstoptime IS NULL rlm_sql (sql): Reserved connection (6) (1) sql: Executing select query: SELECT COUNT(*) FROM radacct WHERE username = 'teste-sql' AND acctstoptime IS NULL rlm_sql (sql): Released connection (6) (1) [sql] = ok (1) } # session = ok (1) Login OK: [teste-sql] (from client CSC-755-rt-01 port 15728647 cli E4:8D:8C:EC:90:A2) (1) Sent Access-Accept Id 17 from 172.31.255.188:1812 to 187.19.96.40:35728 length 0 (1) Mikrotik-Rate-Limit = "32k" (1) Finished request Waking up in 1.9 seconds. (1) Cleaning up request packet ID 17 with timestamp +50 Ready to process requests (2) Received Access-Request Id 17 from 187.19.96.40:35728 to 172.31.255.188:1812 length 136 (2) Service-Type = Framed-User (2) Framed-Protocol = PPP (2) NAS-Port = 15728647 (2) NAS-Port-Type = Ethernet (2) User-Name = "teste-sql" (2) Calling-Station-Id = "E4:8D:8C:EC:90:A2" (2) Called-Station-Id = "CSC-755-rt-01" (2) NAS-Port-Id = "vlan14" (2) User-Password = "senha34" (2) NAS-Identifier = "CSC-755-rt-01" (2) NAS-IP-Address = 187.19.96.40 (2) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default (2) authorize { (2) sql: EXPAND %{User-Name} (2) sql: --> teste-sql (2) sql: SQL-User-Name set to 'teste-sql' rlm_sql (sql): Reserved connection (7) (2) sql: EXPAND SELECT id, username, attribute, value, op FROM radcheck WHERE username = '%{SQL-User-Name}' ORDER BY id (2) sql: --> SELECT id, username, attribute, value, op FROM radcheck WHERE username = 'teste-sql' ORDER BY id (2) sql: Executing select query: SELECT id, username, attribute, value, op FROM radcheck WHERE username = 'teste-sql' ORDER BY id (2) sql: User found in radcheck table (2) sql: Conditional check items matched, merging assignment check items (2) sql: Crypt-Password := "w54qGtgpcqSaw" (2) sql: Pool-Name := "main_pool" (2) sql: EXPAND SELECT id, username, attribute, value, op FROM radreply WHERE username = '%{SQL-User-Name}' ORDER BY id (2) sql: --> SELECT id, username, attribute, value, op FROM radreply WHERE username = 'teste-sql' ORDER BY id (2) sql: Executing select query: SELECT id, username, attribute, value, op FROM radreply WHERE username = 'teste-sql' ORDER BY id (2) sql: EXPAND SELECT groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority (2) sql: --> SELECT groupname FROM radusergroup WHERE username = 'teste-sql' ORDER BY priority (2) sql: Executing select query: SELECT groupname FROM radusergroup WHERE username = 'teste-sql' ORDER BY priority (2) sql: User found in the group table (2) sql: EXPAND SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = '%{SQL-Group}' ORDER BY id (2) sql: --> SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = 'grupo-teste-sql' ORDER BY id (2) sql: Executing select query: SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = 'grupo-teste-sql' ORDER BY id (2) sql: Group "grupo-teste-sql": Conditional check items matched (2) sql: Group "grupo-teste-sql": Merging assignment check items (2) sql: Simultaneous-Use := 1 (2) sql: EXPAND SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = '%{SQL-Group}' ORDER BY id (2) sql: --> SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = 'grupo-teste-sql' ORDER BY id (2) sql: Executing select query: SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = 'grupo-teste-sql' ORDER BY id (2) sql: Group "grupo-teste-sql": Merging reply items (2) sql: Mikrotik-Rate-Limit := "32k" rlm_sql (sql): Released connection (7) rlm_sql (sql): Closing connection (8), from 8 unused connections rlm_sql_mysql: Socket destructor called, closing socket (2) [sql] = ok (2) [pap] = updated (2) } # authorize = updated (2) Found Auth-Type = PAP (2) # Executing group from file /usr/local/etc/raddb/sites-enabled/default (2) Auth-Type PAP { (2) pap: Login attempt with password (2) pap: Comparing with "known-good" Crypt-password (2) pap: User authenticated successfully (2) [pap] = ok (2) } # Auth-Type PAP = ok (2) # Executing section session from file /usr/local/etc/raddb/sites-enabled/default (2) session { (2) sql: EXPAND %{User-Name} (2) sql: --> teste-sql (2) sql: SQL-User-Name set to 'teste-sql' (2) sql: EXPAND SELECT COUNT(*) FROM radacct WHERE username = '%{SQL-User-Name}' AND acctstoptime IS NULL (2) sql: --> SELECT COUNT(*) FROM radacct WHERE username = 'teste-sql' AND acctstoptime IS NULL rlm_sql (sql): Reserved connection (9) (2) sql: Executing select query: SELECT COUNT(*) FROM radacct WHERE username = 'teste-sql' AND acctstoptime IS NULL rlm_sql (sql): Released connection (9) (2) [sql] = ok (2) } # session = ok (2) Login OK: [teste-sql] (from client CSC-755-rt-01 port 15728647 cli E4:8D:8C:EC:90:A2) (2) Sent Access-Accept Id 17 from 172.31.255.188:1812 to 187.19.96.40:35728 length 0 (2) Mikrotik-Rate-Limit = "32k" (2) Finished request Waking up in 1.9 seconds. (2) Cleaning up request packet ID 17 with timestamp +53 Ready to process requests (3) Received Access-Request Id 18 from 187.19.96.40:36982 to 172.31.255.188:1812 length 136 (3) Service-Type = Framed-User (3) Framed-Protocol = PPP (3) NAS-Port = 15728648 (3) NAS-Port-Type = Ethernet (3) User-Name = "teste-sql" (3) Calling-Station-Id = "E4:8D:8C:EC:90:A2" (3) Called-Station-Id = "CSC-755-rt-01" (3) NAS-Port-Id = "vlan14" (3) User-Password = "senha34" (3) NAS-Identifier = "CSC-755-rt-01" (3) NAS-IP-Address = 187.19.96.40 (3) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default (3) authorize { (3) sql: EXPAND %{User-Name} (3) sql: --> teste-sql (3) sql: SQL-User-Name set to 'teste-sql' rlm_sql (sql): Reserved connection (10) (3) sql: EXPAND SELECT id, username, attribute, value, op FROM radcheck WHERE username = '%{SQL-User-Name}' ORDER BY id (3) sql: --> SELECT id, username, attribute, value, op FROM radcheck WHERE username = 'teste-sql' ORDER BY id (3) sql: Executing select query: SELECT id, username, attribute, value, op FROM radcheck WHERE username = 'teste-sql' ORDER BY id (3) sql: User found in radcheck table (3) sql: Conditional check items matched, merging assignment check items (3) sql: Crypt-Password := "w54qGtgpcqSaw" (3) sql: Pool-Name := "main_pool" (3) sql: EXPAND SELECT id, username, attribute, value, op FROM radreply WHERE username = '%{SQL-User-Name}' ORDER BY id (3) sql: --> SELECT id, username, attribute, value, op FROM radreply WHERE username = 'teste-sql' ORDER BY id (3) sql: Executing select query: SELECT id, username, attribute, value, op FROM radreply WHERE username = 'teste-sql' ORDER BY id (3) sql: EXPAND SELECT groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority (3) sql: --> SELECT groupname FROM radusergroup WHERE username = 'teste-sql' ORDER BY priority (3) sql: Executing select query: SELECT groupname FROM radusergroup WHERE username = 'teste-sql' ORDER BY priority (3) sql: User found in the group table (3) sql: EXPAND SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = '%{SQL-Group}' ORDER BY id (3) sql: --> SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = 'grupo-teste-sql' ORDER BY id (3) sql: Executing select query: SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = 'grupo-teste-sql' ORDER BY id (3) sql: Group "grupo-teste-sql": Conditional check items matched (3) sql: Group "grupo-teste-sql": Merging assignment check items (3) sql: Simultaneous-Use := 1 (3) sql: EXPAND SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = '%{SQL-Group}' ORDER BY id (3) sql: --> SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = 'grupo-teste-sql' ORDER BY id (3) sql: Executing select query: SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = 'grupo-teste-sql' ORDER BY id (3) sql: Group "grupo-teste-sql": Merging reply items (3) sql: Mikrotik-Rate-Limit := "32k" rlm_sql (sql): Released connection (10) rlm_sql (sql): Closing connection (11), from 7 unused connections rlm_sql_mysql: Socket destructor called, closing socket (3) [sql] = ok (3) [pap] = updated (3) } # authorize = updated (3) Found Auth-Type = PAP (3) # Executing group from file /usr/local/etc/raddb/sites-enabled/default (3) Auth-Type PAP { (3) pap: Login attempt with password (3) pap: Comparing with "known-good" Crypt-password (3) pap: User authenticated successfully (3) [pap] = ok (3) } # Auth-Type PAP = ok (3) # Executing section session from file /usr/local/etc/raddb/sites-enabled/default (3) session { (3) sql: EXPAND %{User-Name} (3) sql: --> teste-sql (3) sql: SQL-User-Name set to 'teste-sql' (3) sql: EXPAND SELECT COUNT(*) FROM radacct WHERE username = '%{SQL-User-Name}' AND acctstoptime IS NULL (3) sql: --> SELECT COUNT(*) FROM radacct WHERE username = 'teste-sql' AND acctstoptime IS NULL rlm_sql (sql): Reserved connection (12) (3) sql: Executing select query: SELECT COUNT(*) FROM radacct WHERE username = 'teste-sql' AND acctstoptime IS NULL rlm_sql (sql): Released connection (12) (3) [sql] = ok (3) } # session = ok (3) Login OK: [teste-sql] (from client CSC-755-rt-01 port 15728648 cli E4:8D:8C:EC:90:A2) (3) Sent Access-Accept Id 18 from 172.31.255.188:1812 to 187.19.96.40:36982 length 0 (3) Mikrotik-Rate-Limit = "32k" (3) Finished request Waking up in 1.9 seconds. (4) Received Accounting-Request Id 19 from 187.19.96.40:39970 to 172.31.255.188:1813 length 158 (4) Service-Type = Framed-User (4) Framed-Protocol = PPP (4) NAS-Port = 15728648 (4) NAS-Port-Type = Ethernet (4) User-Name = "teste-sql" (4) Calling-Station-Id = "E4:8D:8C:EC:90:A2" (4) Called-Station-Id = "CSC-755-rt-01" (4) NAS-Port-Id = "vlan14" (4) Acct-Session-Id = "81800003" (4) Framed-IP-Address = 0.0.0.0 (4) Acct-Authentic = RADIUS (4) Event-Timestamp = "Oct 18 2016 08:28:53 BRST" (4) Acct-Status-Type = Start (4) NAS-Identifier = "CSC-755-rt-01" (4) Acct-Delay-Time = 0 (4) NAS-IP-Address = 187.19.96.40 (4) # Executing section preacct from file /usr/local/etc/raddb/sites-enabled/default (4) preacct { (4) policy acct_unique { (4) update request { (4) Tmp-String-9 := "ai:" (4) } # update request = noop (4) if (("%{hex:&Class}" =~ /^%{hex:&Tmp-String-9}/) && ("%{string:&Class}" =~ /^ai:([0-9a-f]{32})/i)) { (4) EXPAND %{hex:&Class} (4) --> (4) EXPAND ^%{hex:&Tmp-String-9} (4) --> ^61693a (4) if (("%{hex:&Class}" =~ /^%{hex:&Tmp-String-9}/) && ("%{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) --> 747ce123cf0bf502dfc1fb210db060a6 (4) &Acct-Unique-Session-Id := 747ce123cf0bf502dfc1fb210db060a6 (4) } # update request = noop (4) } # else = noop (4) } # policy acct_unique = noop (4) } # preacct = noop (4) # Executing section accounting from file /usr/local/etc/raddb/sites-enabled/default (4) accounting { (4) sql: EXPAND %{tolower:type.%{Acct-Status-Type}.query} (4) sql: --> type.start.query (4) sql: Using query template 'query' rlm_sql (sql): Reserved connection (13) (4) sql: EXPAND %{User-Name} (4) sql: --> teste-sql (4) sql: SQL-User-Name set to 'teste-sql' (4) 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-ID}:-%{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}') (4) 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 ('81800003', '747ce123cf0bf502dfc1fb210db060a6', 'teste-sql', '', '187.19.96.40', 'vlan14', 'Ethernet', FROM_UNIXTIME(1476786533), FROM_UNIXTIME(1476786533), NULL, '0', 'RADIUS', '', '', '0', '0', 'CSC-755-rt-01', 'E4:8D:8C:EC:90:A2', '', 'Framed-User', 'PPP', '0.0.0.0') (4) sql: EXPAND /usr/local/var/log/radius/sqllog.sql (4) sql: --> /usr/local/var/log/radius/sqllog.sql (4) 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 ('81800003', '747ce123cf0bf502dfc1fb210db060a6', 'teste-sql', '', '187.19.96.40', 'vlan14', 'Ethernet', FROM_UNIXTIME(1476786533), FROM_UNIXTIME(1476786533), NULL, '0', 'RADIUS', '', '', '0', '0', 'CSC-755-rt-01', 'E4:8D:8C:EC:90:A2', '', 'Framed-User', 'PPP', '0.0.0.0') (4) sql: SQL query returned: success (4) sql: 1 record(s) updated rlm_sql (sql): Released connection (13) (4) [sql] = ok (4) attr_filter.accounting_response: EXPAND %{User-Name} (4) attr_filter.accounting_response: --> teste-sql (4) attr_filter.accounting_response: Matched entry DEFAULT at line 12 (4) [attr_filter.accounting_response] = updated (4) } # accounting = updated (4) Sent Accounting-Response Id 19 from 172.31.255.188:1813 to 187.19.96.40:39970 length 0 (4) Finished request (4) Cleaning up request packet ID 19 with timestamp +56 Waking up in 1.9 seconds. (3) Cleaning up request packet ID 18 with timestamp +56 Ready to process requests (5) Received Accounting-Request Id 19 from 187.19.96.40:1073 to 172.31.255.188:1813 length 158 (5) Service-Type = Framed-User (5) Framed-Protocol = PPP (5) NAS-Port = 15728648 (5) NAS-Port-Type = Ethernet (5) User-Name = "teste-sql" (5) Calling-Station-Id = "E4:8D:8C:EC:90:A2" (5) Called-Station-Id = "CSC-755-rt-01" (5) NAS-Port-Id = "vlan14" (5) Acct-Session-Id = "81800003" (5) Framed-IP-Address = 0.0.0.0 (5) Acct-Authentic = RADIUS (5) Event-Timestamp = "Oct 18 2016 08:28:53 BRST" (5) Acct-Status-Type = Start (5) NAS-Identifier = "CSC-755-rt-01" (5) Acct-Delay-Time = 3 (5) NAS-IP-Address = 187.19.96.40 (5) # Executing section preacct from file /usr/local/etc/raddb/sites-enabled/default (5) preacct { (5) policy acct_unique { (5) update request { (5) Tmp-String-9 := "ai:" (5) } # update request = noop (5) if (("%{hex:&Class}" =~ /^%{hex:&Tmp-String-9}/) && ("%{string:&Class}" =~ /^ai:([0-9a-f]{32})/i)) { (5) EXPAND %{hex:&Class} (5) --> (5) EXPAND ^%{hex:&Tmp-String-9} (5) --> ^61693a (5) if (("%{hex:&Class}" =~ /^%{hex:&Tmp-String-9}/) && ("%{string:&Class}" =~ /^ai:([0-9a-f]{32})/i)) -> FALSE (5) else { (5) update request { (5) EXPAND %{md5:%{User-Name},%{Acct-Session-ID},%{%{NAS-IPv6-Address}:-%{NAS-IP-Address}},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}} (5) --> 747ce123cf0bf502dfc1fb210db060a6 (5) &Acct-Unique-Session-Id := 747ce123cf0bf502dfc1fb210db060a6 (5) } # update request = noop (5) } # else = noop (5) } # policy acct_unique = noop (5) } # preacct = noop (5) # Executing section accounting from file /usr/local/etc/raddb/sites-enabled/default (5) accounting { (5) sql: EXPAND %{tolower:type.%{Acct-Status-Type}.query} (5) sql: --> type.start.query (5) sql: Using query template 'query' rlm_sql (sql): Reserved connection (14) (5) sql: EXPAND %{User-Name} (5) sql: --> teste-sql (5) sql: SQL-User-Name set to 'teste-sql' (5) 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-ID}:-%{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}') (5) 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 ('81800003', '747ce123cf0bf502dfc1fb210db060a6', 'teste-sql', '', '187.19.96.40', 'vlan14', 'Ethernet', FROM_UNIXTIME(1476786533), FROM_UNIXTIME(1476786533), NULL, '0', 'RADIUS', '', '', '0', '0', 'CSC-755-rt-01', 'E4:8D:8C:EC:90:A2', '', 'Framed-User', 'PPP', '0.0.0.0') (5) sql: EXPAND /usr/local/var/log/radius/sqllog.sql (5) sql: --> /usr/local/var/log/radius/sqllog.sql (5) 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 ('81800003', '747ce123cf0bf502dfc1fb210db060a6', 'teste-sql', '', '187.19.96.40', 'vlan14', 'Ethernet', FROM_UNIXTIME(1476786533), FROM_UNIXTIME(1476786533), NULL, '0', 'RADIUS', '', '', '0', '0', 'CSC-755-rt-01', 'E4:8D:8C:EC:90:A2', '', 'Framed-User', 'PPP', '0.0.0.0') (5) sql: rlm_sql_mysql: ERROR 1062 (Duplicate entry '747ce123cf0bf502dfc1fb210db060a6' for key 'acctuniqueid'): 23000 (5) sql: SQL query returned: need alt query (5) sql: Trying next query... (5) sql: EXPAND UPDATE radacct SET acctstarttime = FROM_UNIXTIME(%{integer:Event-Timestamp}), acctupdatetime = FROM_UNIXTIME(%{integer:Event-Timestamp}), connectinfo_start = '%{Connect-Info}' WHERE AcctUniqueId = '%{Acct-Unique-Session-Id}' (5) sql: --> UPDATE radacct SET acctstarttime = FROM_UNIXTIME(1476786533), acctupdatetime = FROM_UNIXTIME(1476786533), connectinfo_start = '' WHERE AcctUniqueId = '747ce123cf0bf502dfc1fb210db060a6' (5) sql: EXPAND /usr/local/var/log/radius/sqllog.sql (5) sql: --> /usr/local/var/log/radius/sqllog.sql (5) sql: Executing query: UPDATE radacct SET acctstarttime = FROM_UNIXTIME(1476786533), acctupdatetime = FROM_UNIXTIME(1476786533), connectinfo_start = '' WHERE AcctUniqueId = '747ce123cf0bf502dfc1fb210db060a6' rlm_sql_mysql: Rows matched: 1 Changed: 0 Warnings: 0 (5) sql: SQL query returned: success (5) sql: 1 record(s) updated rlm_sql (sql): Released connection (14) rlm_sql (sql): Closing connection (15), from 6 unused connections rlm_sql_mysql: Socket destructor called, closing socket (5) [sql] = ok (5) attr_filter.accounting_response: EXPAND %{User-Name} (5) attr_filter.accounting_response: --> teste-sql (5) attr_filter.accounting_response: Matched entry DEFAULT at line 12 (5) [attr_filter.accounting_response] = updated (5) } # accounting = updated (5) Sent Accounting-Response Id 19 from 172.31.255.188:1813 to 187.19.96.40:1073 length 0 (5) Finished request (5) Cleaning up request packet ID 19 with timestamp +59 Ready to process requests (6) Received Accounting-Request Id 20 from 187.19.96.40:35154 to 172.31.255.188:1813 length 206 (6) Service-Type = Framed-User (6) Framed-Protocol = PPP (6) NAS-Port = 15728648 (6) NAS-Port-Type = Ethernet (6) User-Name = "teste-sql" (6) Calling-Station-Id = "E4:8D:8C:EC:90:A2" (6) Called-Station-Id = "CSC-755-rt-01" (6) NAS-Port-Id = "vlan14" (6) Acct-Session-Id = "81800003" (6) Framed-IP-Address = 0.0.0.0 (6) Acct-Authentic = RADIUS (6) Event-Timestamp = "Oct 18 2016 08:29:07 BRST" (6) Acct-Session-Time = 14 (6) Acct-Input-Octets = 65 (6) Acct-Input-Gigawords = 0 (6) Acct-Input-Packets = 6 (6) Acct-Output-Octets = 50 (6) Acct-Output-Gigawords = 0 (6) Acct-Output-Packets = 7 (6) Acct-Status-Type = Stop (6) Acct-Terminate-Cause = User-Request (6) NAS-Identifier = "CSC-755-rt-01" (6) Acct-Delay-Time = 0 (6) NAS-IP-Address = 187.19.96.40 (6) # Executing section preacct from file /usr/local/etc/raddb/sites-enabled/default (6) preacct { (6) policy acct_unique { (6) update request { (6) Tmp-String-9 := "ai:" (6) } # update request = noop (6) if (("%{hex:&Class}" =~ /^%{hex:&Tmp-String-9}/) && ("%{string:&Class}" =~ /^ai:([0-9a-f]{32})/i)) { (6) EXPAND %{hex:&Class} (6) --> (6) EXPAND ^%{hex:&Tmp-String-9} (6) --> ^61693a (6) if (("%{hex:&Class}" =~ /^%{hex:&Tmp-String-9}/) && ("%{string:&Class}" =~ /^ai:([0-9a-f]{32})/i)) -> FALSE (6) else { (6) update request { (6) EXPAND %{md5:%{User-Name},%{Acct-Session-ID},%{%{NAS-IPv6-Address}:-%{NAS-IP-Address}},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}} (6) --> 747ce123cf0bf502dfc1fb210db060a6 (6) &Acct-Unique-Session-Id := 747ce123cf0bf502dfc1fb210db060a6 (6) } # update request = noop (6) } # else = noop (6) } # policy acct_unique = noop (6) } # preacct = noop (6) # Executing section accounting from file /usr/local/etc/raddb/sites-enabled/default (6) accounting { (6) sql: EXPAND %{tolower:type.%{Acct-Status-Type}.query} (6) sql: --> type.stop.query (6) sql: Using query template 'query' rlm_sql (sql): Closing connection (16): Hit idle_timeout, was idle for 70 seconds rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql): Closing connection (17): Hit idle_timeout, was idle for 70 seconds rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql): Closing connection (18): Hit idle_timeout, was idle for 70 seconds rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql): Closing connection (19): Hit idle_timeout, was idle for 70 seconds rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql): Closing connection (20): Hit idle_timeout, was idle for 70 seconds rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql): Closing connection (21): Hit idle_timeout, was idle for 70 seconds rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql): Closing connection (22): Hit idle_timeout, was idle for 70 seconds rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql): Closing connection (23): Hit idle_timeout, was idle for 70 seconds rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql): Closing connection (24): Hit idle_timeout, was idle for 70 seconds rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql): Closing connection (25): Hit idle_timeout, was idle for 70 seconds rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql): Closing connection (26): Hit idle_timeout, was idle for 70 seconds rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql): Closing connection (27): Hit idle_timeout, was idle for 70 seconds rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql): Closing connection (28): Hit idle_timeout, was idle for 70 seconds rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql): Closing connection (29): Hit idle_timeout, was idle for 70 seconds rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql): Closing connection (0): Hit idle_timeout, was idle for 70 seconds rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql): Reserved connection (1) (6) sql: EXPAND %{User-Name} (6) sql: --> teste-sql (6) sql: SQL-User-Name set to 'teste-sql' (6) sql: EXPAND UPDATE radacct SET acctstoptime = FROM_UNIXTIME(%{integer:Event-Timestamp}), 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}' (6) sql: --> UPDATE radacct SET acctstoptime = FROM_UNIXTIME(1476786547), acctsessiontime = 14, acctinputoctets = '0' << 32 | '65', acctoutputoctets = '0' << 32 | '50', acctterminatecause = 'User-Request', connectinfo_stop = '' WHERE AcctUniqueId = '747ce123cf0bf502dfc1fb210db060a6' (6) sql: EXPAND /usr/local/var/log/radius/sqllog.sql (6) sql: --> /usr/local/var/log/radius/sqllog.sql (6) sql: Executing query: UPDATE radacct SET acctstoptime = FROM_UNIXTIME(1476786547), acctsessiontime = 14, acctinputoctets = '0' << 32 | '65', acctoutputoctets = '0' << 32 | '50', acctterminatecause = 'User-Request', connectinfo_stop = '' WHERE AcctUniqueId = '747ce123cf0bf502dfc1fb210db060a6' rlm_sql_mysql: Rows matched: 1 Changed: 1 Warnings: 0 (6) sql: SQL query returned: success (6) sql: 1 record(s) updated rlm_sql (sql): Released connection (1) (6) [sql] = ok (6) attr_filter.accounting_response: EXPAND %{User-Name} (6) attr_filter.accounting_response: --> teste-sql (6) attr_filter.accounting_response: Matched entry DEFAULT at line 12 (6) [attr_filter.accounting_response] = updated (6) } # accounting = updated (6) Sent Accounting-Response Id 20 from 172.31.255.188:1813 to 187.19.96.40:35154 length 0 (6) Finished request (6) Cleaning up request packet ID 20 with timestamp +70 Ready to process requests (7) Received Accounting-Request Id 20 from 187.19.96.40:35154 to 172.31.255.188:1813 length 206 (7) Service-Type = Framed-User (7) Framed-Protocol = PPP (7) NAS-Port = 15728648 (7) NAS-Port-Type = Ethernet (7) User-Name = "teste-sql" (7) Calling-Station-Id = "E4:8D:8C:EC:90:A2" (7) Called-Station-Id = "CSC-755-rt-01" (7) NAS-Port-Id = "vlan14" (7) Acct-Session-Id = "81800003" (7) Framed-IP-Address = 0.0.0.0 (7) Acct-Authentic = RADIUS (7) Event-Timestamp = "Oct 18 2016 08:29:07 BRST" (7) Acct-Session-Time = 14 (7) Acct-Input-Octets = 65 (7) Acct-Input-Gigawords = 0 (7) Acct-Input-Packets = 6 (7) Acct-Output-Octets = 50 (7) Acct-Output-Gigawords = 0 (7) Acct-Output-Packets = 7 (7) Acct-Status-Type = Stop (7) Acct-Terminate-Cause = User-Request (7) NAS-Identifier = "CSC-755-rt-01" (7) Acct-Delay-Time = 3 (7) NAS-IP-Address = 187.19.96.40 (7) # Executing section preacct from file /usr/local/etc/raddb/sites-enabled/default (7) preacct { (7) policy acct_unique { (7) update request { (7) Tmp-String-9 := "ai:" (7) } # update request = noop (7) if (("%{hex:&Class}" =~ /^%{hex:&Tmp-String-9}/) && ("%{string:&Class}" =~ /^ai:([0-9a-f]{32})/i)) { (7) EXPAND %{hex:&Class} (7) --> (7) EXPAND ^%{hex:&Tmp-String-9} (7) --> ^61693a (7) if (("%{hex:&Class}" =~ /^%{hex:&Tmp-String-9}/) && ("%{string:&Class}" =~ /^ai:([0-9a-f]{32})/i)) -> FALSE (7) else { (7) update request { (7) EXPAND %{md5:%{User-Name},%{Acct-Session-ID},%{%{NAS-IPv6-Address}:-%{NAS-IP-Address}},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}} (7) --> 747ce123cf0bf502dfc1fb210db060a6 (7) &Acct-Unique-Session-Id := 747ce123cf0bf502dfc1fb210db060a6 (7) } # update request = noop (7) } # else = noop (7) } # policy acct_unique = noop (7) } # preacct = noop (7) # Executing section accounting from file /usr/local/etc/raddb/sites-enabled/default (7) accounting { (7) sql: EXPAND %{tolower:type.%{Acct-Status-Type}.query} (7) sql: --> type.stop.query (7) sql: Using query template 'query' rlm_sql (sql): Reserved connection (3) (7) sql: EXPAND %{User-Name} (7) sql: --> teste-sql (7) sql: SQL-User-Name set to 'teste-sql' (7) sql: EXPAND UPDATE radacct SET acctstoptime = FROM_UNIXTIME(%{integer:Event-Timestamp}), 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}' (7) sql: --> UPDATE radacct SET acctstoptime = FROM_UNIXTIME(1476786547), acctsessiontime = 14, acctinputoctets = '0' << 32 | '65', acctoutputoctets = '0' << 32 | '50', acctterminatecause = 'User-Request', connectinfo_stop = '' WHERE AcctUniqueId = '747ce123cf0bf502dfc1fb210db060a6' (7) sql: EXPAND /usr/local/var/log/radius/sqllog.sql (7) sql: --> /usr/local/var/log/radius/sqllog.sql (7) sql: Executing query: UPDATE radacct SET acctstoptime = FROM_UNIXTIME(1476786547), acctsessiontime = 14, acctinputoctets = '0' << 32 | '65', acctoutputoctets = '0' << 32 | '50', acctterminatecause = 'User-Request', connectinfo_stop = '' WHERE AcctUniqueId = '747ce123cf0bf502dfc1fb210db060a6' rlm_sql_mysql: Rows matched: 1 Changed: 0 Warnings: 0 (7) sql: SQL query returned: success (7) sql: 1 record(s) updated rlm_sql (sql): Released connection (3) (7) [sql] = ok (7) attr_filter.accounting_response: EXPAND %{User-Name} (7) attr_filter.accounting_response: --> teste-sql (7) attr_filter.accounting_response: Matched entry DEFAULT at line 12 (7) [attr_filter.accounting_response] = updated (7) } # accounting = updated (7) Sent Accounting-Response Id 20 from 172.31.255.188:1813 to 187.19.96.40:35154 length 0 (7) Finished request (7) Cleaning up request packet ID 20 with timestamp +73 Ready to process requests (8) Received Accounting-Request Id 20 from 187.19.96.40:35154 to 172.31.255.188:1813 length 206 (8) Service-Type = Framed-User (8) Framed-Protocol = PPP (8) NAS-Port = 15728648 (8) NAS-Port-Type = Ethernet (8) User-Name = "teste-sql" (8) Calling-Station-Id = "E4:8D:8C:EC:90:A2" (8) Called-Station-Id = "CSC-755-rt-01" (8) NAS-Port-Id = "vlan14" (8) Acct-Session-Id = "81800003" (8) Framed-IP-Address = 0.0.0.0 (8) Acct-Authentic = RADIUS (8) Event-Timestamp = "Oct 18 2016 08:29:07 BRST" (8) Acct-Session-Time = 14 (8) Acct-Input-Octets = 65 (8) Acct-Input-Gigawords = 0 (8) Acct-Input-Packets = 6 (8) Acct-Output-Octets = 50 (8) Acct-Output-Gigawords = 0 (8) Acct-Output-Packets = 7 (8) Acct-Status-Type = Stop (8) Acct-Terminate-Cause = User-Request (8) NAS-Identifier = "CSC-755-rt-01" (8) Acct-Delay-Time = 6 (8) NAS-IP-Address = 187.19.96.40 (8) # Executing section preacct from file /usr/local/etc/raddb/sites-enabled/default (8) preacct { (8) policy acct_unique { (8) update request { (8) Tmp-String-9 := "ai:" (8) } # update request = noop (8) if (("%{hex:&Class}" =~ /^%{hex:&Tmp-String-9}/) && ("%{string:&Class}" =~ /^ai:([0-9a-f]{32})/i)) { (8) EXPAND %{hex:&Class} (8) --> (8) EXPAND ^%{hex:&Tmp-String-9} (8) --> ^61693a (8) if (("%{hex:&Class}" =~ /^%{hex:&Tmp-String-9}/) && ("%{string:&Class}" =~ /^ai:([0-9a-f]{32})/i)) -> FALSE (8) else { (8) update request { (8) EXPAND %{md5:%{User-Name},%{Acct-Session-ID},%{%{NAS-IPv6-Address}:-%{NAS-IP-Address}},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}} (8) --> 747ce123cf0bf502dfc1fb210db060a6 (8) &Acct-Unique-Session-Id := 747ce123cf0bf502dfc1fb210db060a6 (8) } # update request = noop (8) } # else = noop (8) } # policy acct_unique = noop (8) } # preacct = noop (8) # Executing section accounting from file /usr/local/etc/raddb/sites-enabled/default (8) accounting { (8) sql: EXPAND %{tolower:type.%{Acct-Status-Type}.query} (8) sql: --> type.stop.query (8) sql: Using query template 'query' rlm_sql (sql): Reserved connection (4) (8) sql: EXPAND %{User-Name} (8) sql: --> teste-sql (8) sql: SQL-User-Name set to 'teste-sql' (8) sql: EXPAND UPDATE radacct SET acctstoptime = FROM_UNIXTIME(%{integer:Event-Timestamp}), 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}' (8) sql: --> UPDATE radacct SET acctstoptime = FROM_UNIXTIME(1476786547), acctsessiontime = 14, acctinputoctets = '0' << 32 | '65', acctoutputoctets = '0' << 32 | '50', acctterminatecause = 'User-Request', connectinfo_stop = '' WHERE AcctUniqueId = '747ce123cf0bf502dfc1fb210db060a6' (8) sql: EXPAND /usr/local/var/log/radius/sqllog.sql (8) sql: --> /usr/local/var/log/radius/sqllog.sql (8) sql: Executing query: UPDATE radacct SET acctstoptime = FROM_UNIXTIME(1476786547), acctsessiontime = 14, acctinputoctets = '0' << 32 | '65', acctoutputoctets = '0' << 32 | '50', acctterminatecause = 'User-Request', connectinfo_stop = '' WHERE AcctUniqueId = '747ce123cf0bf502dfc1fb210db060a6' rlm_sql_mysql: Rows matched: 1 Changed: 0 Warnings: 0 (8) sql: SQL query returned: success (8) sql: 1 record(s) updated rlm_sql (sql): Released connection (4) (8) [sql] = ok (8) attr_filter.accounting_response: EXPAND %{User-Name} (8) attr_filter.accounting_response: --> teste-sql (8) attr_filter.accounting_response: Matched entry DEFAULT at line 12 (8) [attr_filter.accounting_response] = updated (8) } # accounting = updated (8) Sent Accounting-Response Id 20 from 172.31.255.188:1813 to 187.19.96.40:35154 length 0 (8) Finished request (8) Cleaning up request packet ID 20 with timestamp +76 Ready to process requests This is just one connection running and I saw that 0, 1, 2 and 3 are all Access-Request: (0) Received Access-Request Id 17 from 187.19.96.40:35728 to 172.31.255.188:1812 length 136 (0) Login OK: [teste-sql] (from client CSC-755-rt-01 port 15728647 cli E4:8D:8C:EC:90:A2) (1) Received Access-Request Id 17 from 187.19.96.40:35728 to 172.31.255.188:1812 length 136 (1) Login OK: [teste-sql] (from client CSC-755-rt-01 port 15728647 cli E4:8D:8C:EC:90:A2) (2) Received Access-Request Id 17 from 187.19.96.40:35728 to 172.31.255.188:1812 length 136 (2) Login OK: [teste-sql] (from client CSC-755-rt-01 port 15728647 cli E4:8D:8C:EC:90:A2) (3) Received Access-Request Id 18 from 187.19.96.40:36982 to 172.31.255.188:1812 length 136 (3) Login OK: [teste-sql] (from client CSC-755-rt-01 port 15728648 cli E4:8D:8C:EC:90:A2) But for some reasons I can't find the only Accounting-Request is made to connection number 3 (NAS-Port = 15728648): (4) Received Accounting-Request Id 19 from 187.19.96.40:39970 to 172.31.255.188:1813 length 158 (4) Service-Type = Framed-User (4) Framed-Protocol = PPP (4) NAS-Port = 15728648 (4) NAS-Port-Type = Ethernet (4) User-Name = "teste-sql" (4) Calling-Station-Id = "E4:8D:8C:EC:90:A2" (4) Called-Station-Id = "CSC-755-rt-01" (4) NAS-Port-Id = "vlan14" (4) Acct-Session-Id = "81800003" (4) Framed-IP-Address = 0.0.0.0 (4) Acct-Authentic = RADIUS (4) Event-Timestamp = "Oct 18 2016 08:28:53 BRST" (4) Acct-Status-Type = Start (4) NAS-Identifier = "CSC-755-rt-01" (4) Acct-Delay-Time = 0 (4) NAS-IP-Address = 187.19.96.40 Them, again I have a repeated Accounting-Request that I can't explain on number 5: (5) Received Accounting-Request Id 19 from 187.19.96.40:1073 to 172.31.255.188:1813 length 158 (5) Service-Type = Framed-User (5) Framed-Protocol = PPP (5) NAS-Port = 15728648 (5) NAS-Port-Type = Ethernet (5) User-Name = "teste-sql" (5) Calling-Station-Id = "E4:8D:8C:EC:90:A2" (5) Called-Station-Id = "CSC-755-rt-01" (5) NAS-Port-Id = "vlan14" (5) Acct-Session-Id = "81800003" (5) Framed-IP-Address = 0.0.0.0 (5) Acct-Authentic = RADIUS (5) Event-Timestamp = "Oct 18 2016 08:28:53 BRST" (5) Acct-Status-Type = Start (5) NAS-Identifier = "CSC-755-rt-01" (5) Acct-Delay-Time = 3 (5) NAS-IP-Address = 187.19.96.40 the Acct-Delay-Time is set to 3 (seconds) which is the exact time set to PPPoE NAS Server as a Radius Timeout: [admin@CSC-755-rt-01] > radius print detail Flags: X - disabled 0 service=ppp called-id="" domain="" address=172.31.255.188 secret="testing123" authentication-port=1812 accounting-port=1813 timeout=3s accounting-backup=no realm="" src-address=187.19.96.40 Then the Radius register an Accounting-Request as stop when I stop the test connection: (6) Received Accounting-Request Id 20 from 187.19.96.40:35154 to 172.31.255.188:1813 length 206 (6) Service-Type = Framed-User (6) Framed-Protocol = PPP (6) NAS-Port = 15728648 (6) NAS-Port-Type = Ethernet (6) User-Name = "teste-sql" (6) Calling-Station-Id = "E4:8D:8C:EC:90:A2" (6) Called-Station-Id = "CSC-755-rt-01" (6) NAS-Port-Id = "vlan14" (6) Acct-Session-Id = "81800003" (6) Framed-IP-Address = 0.0.0.0 (6) Acct-Authentic = RADIUS (6) Event-Timestamp = "Oct 18 2016 08:29:07 BRST" (6) Acct-Session-Time = 14 (6) Acct-Input-Octets = 65 (6) Acct-Input-Gigawords = 0 (6) Acct-Input-Packets = 6 (6) Acct-Output-Octets = 50 (6) Acct-Output-Gigawords = 0 (6) Acct-Output-Packets = 7 (6) Acct-Status-Type = Stop (6) Acct-Terminate-Cause = User-Request (6) NAS-Identifier = "CSC-755-rt-01" (6) Acct-Delay-Time = 0 (6) NAS-IP-Address = 187.19.96.40 And again, exact 3 seconds later, a new request as number 7: (7) Received Accounting-Request Id 20 from 187.19.96.40:35154 to 172.31.255.188:1813 length 206 (7) Service-Type = Framed-User (7) Framed-Protocol = PPP (7) NAS-Port = 15728648 (7) NAS-Port-Type = Ethernet (7) User-Name = "teste-sql" (7) Calling-Station-Id = "E4:8D:8C:EC:90:A2" (7) Called-Station-Id = "CSC-755-rt-01" (7) NAS-Port-Id = "vlan14" (7) Acct-Session-Id = "81800003" (7) Framed-IP-Address = 0.0.0.0 (7) Acct-Authentic = RADIUS (7) Event-Timestamp = "Oct 18 2016 08:29:07 BRST" (7) Acct-Session-Time = 14 (7) Acct-Input-Octets = 65 (7) Acct-Input-Gigawords = 0 (7) Acct-Input-Packets = 6 (7) Acct-Output-Octets = 50 (7) Acct-Output-Gigawords = 0 (7) Acct-Output-Packets = 7 (7) Acct-Status-Type = Stop (7) Acct-Terminate-Cause = User-Request (7) NAS-Identifier = "CSC-755-rt-01" (7) Acct-Delay-Time = 3 (7) NAS-IP-Address = 187.19.96.40 And in this I have a third try with 6 seconds as request 8: (8) Received Accounting-Request Id 20 from 187.19.96.40:35154 to 172.31.255.188:1813 length 206 (8) Service-Type = Framed-User (8) Framed-Protocol = PPP (8) NAS-Port = 15728648 (8) NAS-Port-Type = Ethernet (8) User-Name = "teste-sql" (8) Calling-Station-Id = "E4:8D:8C:EC:90:A2" (8) Called-Station-Id = "CSC-755-rt-01" (8) NAS-Port-Id = "vlan14" (8) Acct-Session-Id = "81800003" (8) Framed-IP-Address = 0.0.0.0 (8) Acct-Authentic = RADIUS (8) Event-Timestamp = "Oct 18 2016 08:29:07 BRST" (8) Acct-Session-Time = 14 (8) Acct-Input-Octets = 65 (8) Acct-Input-Gigawords = 0 (8) Acct-Input-Packets = 6 (8) Acct-Output-Octets = 50 (8) Acct-Output-Gigawords = 0 (8) Acct-Output-Packets = 7 (8) Acct-Status-Type = Stop (8) Acct-Terminate-Cause = User-Request (8) NAS-Identifier = "CSC-755-rt-01" (8) Acct-Delay-Time = 6 (8) NAS-IP-Address = 187.19.96.40 I know there is something I am missing in FreeRadius but I am not being able to find out what. I hope someone can help me something I didn't see. The NAS configuration is the same I use on older FreeRadius version (and it's working fine). Atenciosamente, *Nataniel Klug* | nataniel.klug(a)gmail.com

2 2

No statistics being returned with 3.1.x status site
by Graham Clinch 18 Oct '16

18 Oct '16

Hi Folks, Is anybody succeessfully getting statistics from a 'status' type port using v3.1.x? It works as expected with 3.0.x, but with 3.1 I only get a plain 'Access-Accept' -=- $ echo "Message-Authenticator = 0x00, FreeRADIUS-Statistics-Type = 3" | radclient -x localhost:18121 status adminsecret Sent Status-Server Id 101 from 0.0.0.0:44494 to 127.0.0.1:18121 length 50 Message-Authenticator = 0x00 FreeRADIUS-Statistics-Type = Auth-Acct Received Access-Accept Id 101 from 127.0.0.1:18121 to 0.0.0.0:0 via lo length 20 -=- The only change to the stock config is linking sites-available/status into sites-enabled: -=- [...] server status { # from file /usr/local/etc/raddb/sites-enabled/status } # server status radiusd: #### Opening IP addresses and Ports #### Listening on auth address * port 1812 bound to server default Listening on acct address * port 1813 bound to server default Listening on auth address :: port 1812 bound to server default Listening on acct address :: port 1813 bound to server default Listening on auth address 127.0.0.1 port 18120 bound to server inner-tunnel Listening on status address 127.0.0.1 port 18121 bound to server status Listening on proxy address * port 60122 Listening on proxy address :: port 59166 Ready to process requests (1) Received Status-Server Id 101 from 127.0.0.1:44494 to 127.0.0.1:18121 via lo length 50 (1) Message-Authenticator = 0xc7dc212dc934b93eba6845d5ca0d9594 (1) FreeRADIUS-Statistics-Type = Auth-Acct (1) Running Autz-Type Status-Server from file /usr/local/etc/raddb/sites-enabled/status (1) Autz-Type Status-Server { (1) ok (ok) (1) } # Autz-Type Status-Server (ok) (1) Processing SNMP stats request (1) Sent Access-Accept Id 101 from 127.0.0.1:18121 to 127.0.0.1:44494 via lo length 0 (1) Finished request Waking up in 4.9 seconds. (1) Cleaning up request packet ID 101 with timestamp +10 Ready to process requests -=- ta, Graham

2 1

Re: No statistics being returned with 3.1.x status site
by Wussler, Doug 18 Oct '16

18 Oct '16

Graham - In response to: "Is anybody succeessfully getting statistics from a 'status' type port using v3.1.x? It works as expected with 3.0.x, but with 3.1 I only get a plain 'Access-Accept'" Interesting. I am seeing this issue with 3.0.11. I used to get statistics just fine when running version 2. After upgrading to 3.0.11 I noticed I only receive an Access-Accept. I just hadn't had time to look into it any further. Were you using 3.0.11 when you received statistics or something prior to 3.0.11? Doug Wussler Florida State University. ________________________________ From: Freeradius-Users <freeradius-users-bounces+doug.wussler=fsu.edu(a)lists.freeradius.org> on behalf of freeradius-users-request(a)lists.freeradius.org <freeradius-users-request(a)lists.freeradius.org> Sent: Tuesday, October 18, 2016 6:00 AM To: freeradius-users(a)lists.freeradius.org Subject: Freeradius-Users Digest, Vol 138, Issue 39 Send Freeradius-Users mailing list submissions to freeradius-users(a)lists.freeradius.org To subscribe or unsubscribe via the World Wide Web, visit http://lists.freeradius.org/mailman/listinfo/freeradius-users or, via email, send a message with subject or body 'help' to freeradius-users-request(a)lists.freeradius.org You can reach the person managing the list at freeradius-users-owner(a)lists.freeradius.org When replying, please edit your Subject line so it is more specific than "Re: Contents of Freeradius-Users digest..." Today's Topics: 1. Re: Linelog & radmin (Peter Balsianok) 2. Re: Linelog & radmin (Alan DeKok) 3. Re: Use of buffered-sql for logging auth data to db (Alan DeKok) 4. Re: split_username_nai clobbering user-name? (Alan DeKok) 5. Re: EAP-TTLS not working (Marlen Caemmerer) 6. No statistics being returned with 3.1.x status site (Graham Clinch) ---------------------------------------------------------------------- Message: 1 Date: Mon, 17 Oct 2016 19:33:06 +0200 From: Peter Balsianok <balsianok.peter(a)gmail.com> To: FreeRadius users mailing list <freeradius-users(a)lists.freeradius.org> Subject: Re: Linelog & radmin Message-ID: <CANNcOyyTGGkdE=Os=_Hm4hMxXYHi895nq367Wj3TF2F6kPzXqw(a)mail.gmail.com> Content-Type: text/plain; charset=UTF-8 Well, i need to have the content of REQUEST,CONTROL & REPLY for solving customer trouble tickets. I want to have it on the same place as main log. I see benefit to have HUPing in the rad_linelog (e.g. log rotation). At this moment i have only one options, after log rotation i have to restart whole server. Linelog configuration: linelog log_request { filename = ${log.file} format = "%t : Info: REQUEST(%{User-Name}): %{pairs:request:}" } linelog log_control { filename = ${log.file} format = "%t : Info: CONTROL(%{User-Name}): %{pairs:control:}" } linelog log_proxy_request { filename = ${log.file} format = "%t : Info: PROXY-REQUEST(%{User-Name}): %{pairs:proxy-request:}" } linelog log_reply { filename = ${log.file} format = "%t : Info REPLY(%{User-Name}): %{pairs:reply:}" } linelog log_proxy_reply { filename = ${log.file} format = "%t : Info PROXY-REPLY(%{User-Name}): Packet-Type=%{proxy-reply:Packet-Type} %{pairs:proxy-reply:}" } On Mon, Oct 17, 2016 at 5:36 PM, Alan DeKok <aland(a)deployingradius.com> wrote: > On Oct 17, 2016, at 4:29 AM, Peter Balsianok <balsianok.peter(a)gmail.com> > wrote: > > > > Hi, > > > > When i use radmin ... -e 'hup main.log', linelog (log_request, > log_control > > & log_reply) will not write information into main.log. Why ? > > linelog doesn't write messages to the main log. You can configure it to > write to the same *filename*. But that's different. > > And if you HUP the main log, you didn't HUP linelog, and so it doesn't > change. > > Perhaps you could explain how you've configured linelog, and why you > expect that HUPing the main log will also cause linelog to get HUP'd, too. > > Alan DeKok. > - > List info/subscribe/unsubscribe? See http://www.freeradius.org/ > list/users.html ------------------------------ Message: 2 Date: Mon, 17 Oct 2016 14:52:27 -0400 From: Alan DeKok <aland(a)deployingradius.com> To: FreeRadius users mailing list <freeradius-users(a)lists.freeradius.org> Subject: Re: Linelog & radmin Message-ID: <7A5E56C8-FF2C-451E-B5A1-642839579F66(a)deployingradius.com> Content-Type: text/plain; charset=us-ascii On Oct 17, 2016, at 1:33 PM, Peter Balsianok <balsianok.peter(a)gmail.com> wrote: > > Well, i need to have the content of REQUEST,CONTROL & REPLY for solving > customer trouble tickets. I want to have it on the same place as main log. Why does it need to be the same place as the main log? It shouldn't matter that much. > I see benefit to have HUPing in the rad_linelog (e.g. log rotation). At > this moment i have only one options, after log rotation i have to restart > whole server. You can HUP main.log, and then HUP each linelog module individually. Some messages may go to the old file, but it should generally work. Or, send a patch which has the linelog module do logging via the main log API. The problem will then go away. Alan DeKok. ------------------------------ Message: 3 Date: Mon, 17 Oct 2016 14:53:34 -0400 From: Alan DeKok <aland(a)deployingradius.com> To: FreeRadius users mailing list <freeradius-users(a)lists.freeradius.org> Subject: Re: Use of buffered-sql for logging auth data to db Message-ID: <28744D61-135B-443F-B2F6-D9A4B262F4D3(a)deployingradius.com> Content-Type: text/plain; charset=us-ascii On Oct 17, 2016, at 11:46 AM, Alex Sharaz <alex.sharaz(a)york.ac.uk> wrote: > > Question - can you use the FR 3.0.x control interface to get some form of > status of any db pools being used, or even any errors generated when > writing to a DB ? radmin> help Will print out all of the commands that are available. > Failing that, guess I could grep radius.log looking for specific text > strings relating to > Error: rlm_sql (sql): Last connection attempt failed, waiting 30 seconds > before retrying Yes. We're looking at fixing this all for 4.0... but that may require some re-design. Alan DeKok. ------------------------------ Message: 4 Date: Mon, 17 Oct 2016 15:49:21 -0400 From: Alan DeKok <aland(a)deployingradius.com> To: FreeRadius users mailing list <freeradius-users(a)lists.freeradius.org> Subject: Re: split_username_nai clobbering user-name? Message-ID: <2ECCFC3A-BBEC-444A-AC65-1891D0F227CD(a)deployingradius.com> Content-Type: text/plain; charset=us-ascii On Oct 17, 2016, at 11:53 AM, Adam Bishop <Adam.Bishop(a)jisc.ac.uk> wrote: > > Hopefully the final issue I have porting this config! > > I'm using the suffix module for proxying, and the split_username_nai policy. > > If I put suffix before split, everything is fine. If I put split before suffix, proxying breaks because the suffix module seems to use Stripped-User-Name. Yes. That's by design, unfortunately. It's so you can have multiple prefixes / suffixes, and have the modules just do the right thing. > For my configuration, I don't think it matters which order I call the module and the policy in, but I'm surprised by the behaviour - I can't see the policy updating the User-Name entry. It updates the Stripped-User-Name. Which is the default user name for suffix, LDAP lookups, etc. You can just write some "unlang" yourself to re-implement the "suffix" module. Alan DeKok. ------------------------------ Message: 5 Date: Mon, 17 Oct 2016 22:39:08 +0200 From: Marlen Caemmerer <caemmerer(a)ash-berlin.eu> To: FreeRadius users mailing list <freeradius-users(a)lists.freeradius.org> Subject: Re: EAP-TTLS not working Message-ID: <1a2fabbd2a396bd2885b9bf4ccc36107(a)ash-berlin.eu> Content-Type: text/plain; charset=UTF-8 Am 2016-10-17 15:57, schrieb Alan DeKok: >> On Oct 17, 2016, at 9:35 AM, Marlen Caemmerer <caemmerer(a)ash-berlin.eu> wrote: >> >> This is the debug output of a client that connected. > > There's no final Access-Accept in the debug output. > > And if you're debugging issues with clients not connecting, you need to show the debug output for a client which doesn't connect. Sorry for not being precise. I wanted to write you have the output of the regarding Mac client that cannot connect. Windows 8/10 are working fine, though. Mit freundlichen Grüßen Marlen Caemmerer -- ************************************************ Alice Salomon Hochschule Computerzentrum Marlen Caemmerer Alice-Salomon-Platz 5 12627 Berlin Email: caemmerer(a)ash-berlin.eu ************************************************ ------------------------------ Message: 6 Date: Mon, 17 Oct 2016 23:20:14 +0100 From: Graham Clinch <g.clinch(a)lancaster.ac.uk> To: FreeRadius users mailing list <freeradius-users(a)lists.freeradius.org> Subject: No statistics being returned with 3.1.x status site Message-ID: <edc4177a-7e7b-2eb5-62d9-8fc6afc8c1a3(a)lancaster.ac.uk> Content-Type: text/plain; charset=utf-8; format=flowed Hi Folks, Is anybody succeessfully getting statistics from a 'status' type port using v3.1.x? It works as expected with 3.0.x, but with 3.1 I only get a plain 'Access-Accept' -=- $ echo "Message-Authenticator = 0x00, FreeRADIUS-Statistics-Type = 3" | radclient -x localhost:18121 status adminsecret Sent Status-Server Id 101 from 0.0.0.0:44494 to 127.0.0.1:18121 length 50 Message-Authenticator = 0x00 FreeRADIUS-Statistics-Type = Auth-Acct Received Access-Accept Id 101 from 127.0.0.1:18121 to 0.0.0.0:0 via lo length 20 -=- The only change to the stock config is linking sites-available/status into sites-enabled: -=- [...] server status { # from file /usr/local/etc/raddb/sites-enabled/status } # server status radiusd: #### Opening IP addresses and Ports #### Listening on auth address * port 1812 bound to server default Listening on acct address * port 1813 bound to server default Listening on auth address :: port 1812 bound to server default Listening on acct address :: port 1813 bound to server default Listening on auth address 127.0.0.1 port 18120 bound to server inner-tunnel Listening on status address 127.0.0.1 port 18121 bound to server status Listening on proxy address * port 60122 Listening on proxy address :: port 59166 Ready to process requests (1) Received Status-Server Id 101 from 127.0.0.1:44494 to 127.0.0.1:18121 via lo length 50 (1) Message-Authenticator = 0xc7dc212dc934b93eba6845d5ca0d9594 (1) FreeRADIUS-Statistics-Type = Auth-Acct (1) Running Autz-Type Status-Server from file /usr/local/etc/raddb/sites-enabled/status (1) Autz-Type Status-Server { (1) ok (ok) (1) } # Autz-Type Status-Server (ok) (1) Processing SNMP stats request (1) Sent Access-Accept Id 101 from 127.0.0.1:18121 to 127.0.0.1:44494 via lo length 0 (1) Finished request Waking up in 4.9 seconds. (1) Cleaning up request packet ID 101 with timestamp +10 Ready to process requests -=- ta, Graham ------------------------------ Subject: Digest Footer - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html FreeRADIUS -- users' list info<http://www.freeradius.org/list/users.html> www.freeradius.org Users' List Information. The freeradius-users mailing list is for users of the FreeRADIUS server not Cistron's server! There are a few house-rules to which we'd like ... ------------------------------ End of Freeradius-Users Digest, Vol 138, Issue 39 *************************************************

2 1

Freeradius-training
by Yelladog 18 Oct '16

18 Oct '16

Any plans to offer the intermediate class that's described on the network radius website in the near future? Dustin Yelladogenterprises(a)gmail.com

1 0

split_username_nai clobbering user-name?
by Adam Bishop 17 Oct '16

17 Oct '16

Hopefully the final issue I have porting this config! I'm using the suffix module for proxying, and the split_username_nai policy. If I put suffix before split, everything is fine. If I put split before suffix, proxying breaks because the suffix module seems to use Stripped-User-Name. For my configuration, I don't think it matters which order I call the module and the policy in, but I'm surprised by the behaviour - I can't see the policy updating the User-Name entry. Failure: (58) policy split_username_nai { (58) if (&User-Name && (&User-Name =~ /^([^@]*)(@([-[:alnum:]]+\.[-[:alnum:].]+))?$/)) { No matches Adding 4 matches (58) if (&User-Name && (&User-Name =~ /^([^@]*)(@([-[:alnum:]]+\.[-[:alnum:].]+))?$/)) -> TRUE (58) if (&User-Name && (&User-Name =~ /^([^@]*)(@([-[:alnum:]]+\.[-[:alnum:].]+))?$/)) { (58) update request { (58) 1/4 Found: anonymous (10) (58) EXPAND %{1} (58) --> anonymous (58) &Stripped-User-Name := anonymous (58) 3/4 Found: dev.ja.net (11) (58) EXPAND %{3} (58) --> dev.ja.net (58) &Stripped-User-Domain = dev.ja.net (58) } # update request = noop (58) modsingle[authorize]: calling updated (rlm_always) (58) modsingle[authorize]: returned from updated (rlm_always) (58) [updated] = updated (58) } # if (&User-Name && (&User-Name =~ /^([^@]*)(@([-[:alnum:]]+\.[-[:alnum:].]+))?$/)) = updated (58) ... skipping else: Preceding "if" was taken (58) } # policy split_username_nai = updated (58) modsingle[authorize]: calling suffix (rlm_realm) (58) suffix: Checking for suffix after "@" (58) suffix: No '@' in User-Name = "anonymous", looking up realm NULL (58) suffix: No trust router configured, skipping dynamic realm lookup (58) suffix: No such realm "NULL" (58) modsingle[authorize]: returned from suffix (rlm_realm) (58) [suffix] = noop Success: (58) modsingle[authorize]: calling suffix (rlm_realm) (58) suffix: Checking for suffix after "@" (58) suffix: Looking up realm "dev.ja.net" for User-Name = "anonymous(a)dev.ja.net" (58) suffix: No trust router configured, skipping dynamic realm lookup (58) suffix: No such realm "dev.ja.net" (58) modsingle[authorize]: returned from suffix (rlm_realm) (58) [suffix] = noop (58) policy split_username_nai { (58) if (&User-Name && (&User-Name =~ /^([^@]*)(@([-[:alnum:]]+\.[-[:alnum:].]+))?$/)) { No matches Adding 4 matches (58) if (&User-Name && (&User-Name =~ /^([^@]*)(@([-[:alnum:]]+\.[-[:alnum:].]+))?$/)) -> TRUE (58) if (&User-Name && (&User-Name =~ /^([^@]*)(@([-[:alnum:]]+\.[-[:alnum:].]+))?$/)) { (58) update request { (58) 1/4 Found: anonymous (10) (58) EXPAND %{1} (58) --> anonymous (58) &Stripped-User-Name := anonymous (58) 3/4 Found: dev.ja.net (11) (58) EXPAND %{3} (58) --> dev.ja.net (58) &Stripped-User-Domain = dev.ja.net (58) } # update request = noop (58) modsingle[authorize]: calling updated (rlm_always) (58) modsingle[authorize]: returned from updated (rlm_always) (58) [updated] = updated (58) } # if (&User-Name && (&User-Name =~ /^([^@]*)(@([-[:alnum:]]+\.[-[:alnum:].]+))?$/)) = updated (58) ... skipping else: Preceding "if" was taken (58) } # policy split_username_nai = updated Regards, Adam Bishop gpg: E75B 1F92 6407 DFDF 9F1C BF10 C993 2504 6609 D460 jisc.ac.uk Jisc is a registered charity (number 1149740) and a company limited by guarantee which is registered in England under Company No. 5747339, VAT No. GB 197 0632 86. Jisc’s registered office is: One Castlepark, Tower Hill, Bristol, BS2 0JA. T 0203 697 5800. Jisc Services Limited is a wholly owned Jisc subsidiary and a company limited by guarantee which is registered in England under company number 2881024, VAT number GB 197 0632 86. The registered office is: One Castle Park, Tower Hill, Bristol BS2 0JA. T 0203 697 5800.

2 2

Use of buffered-sql for logging auth data to db
by Alex Sharaz 17 Oct '16

17 Oct '16

FR 3.0.12 Is the use of the buffered-sql virtual host just for processing accounting data ? What about radpostauth data ? Just set up the buffered-sql config and I can see that a file called detail.work has been created .... with Accounting packets in it. Is this file supposed to change size as records get processed? currently just using a file called detail and not detail-<timestamp .....> A

3 6