Hi all, I've removed the change to hints. In case it's relevant, this FreeRADIUS deployment was deployed using the DaloRADIUS instructions, including their web GUI. MS-CHAPv2 works perfectly when I try to connect as testlane5, but when I authenticate as testlane5@test.net.nz, it doesn't work. I understand the suggestion to use NT-Password. I have two questions: - How do I hash to get NT-Password prior to INSERT into the database? - If this is the issue, why does it connect normally without the realm? The user information is in the MySQL database, and does not include realm, i.e. I've used testlane5 rather than testlane5@test.net.nz as the username in the database I need this to work, to enable a user to use any realm configured in FreeRADIUS. I'm using ClearText-Password, shown below: mysql> select * from radcheck where id=189\G; *************************** 1. row *************************** id: 189 username: testlane5 attribute: Cleartext-Password op: := value: s8fds9856f 1 row in set (0.00 sec) ERROR: No query specified mysql> Current debug output: [root@radius-220q ~]# radiusd -X radiusd: FreeRADIUS Version 2.2.6, for host x86_64-redhat-linux-gnu, built on Jul 18 2017 at 12:13:14 Copyright (C) 1999-2013 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 configuration file /etc/raddb/radiusd.conf including configuration file /etc/raddb/proxy.conf including configuration file /etc/raddb/clients.conf including files in directory /etc/raddb/modules/ including configuration file /etc/raddb/modules/pam including configuration file /etc/raddb/modules/digest including configuration file /etc/raddb/modules/ippool including configuration file /etc/raddb/modules/etc_group including configuration file /etc/raddb/modules/cui including configuration file /etc/raddb/modules/dhcp_sqlippool including configuration file /etc/raddb/modules/opendirectory including configuration file /etc/raddb/modules/wimax including configuration file /etc/raddb/modules/realm including configuration file /etc/raddb/modules/passwd including configuration file /etc/raddb/modules/acct_unique including configuration file /etc/raddb/modules/soh including configuration file /etc/raddb/modules/redis including configuration file /etc/raddb/modules/sql_log including configuration file /etc/raddb/modules/ntlm_auth including configuration file /etc/raddb/modules/attr_rewrite including configuration file /etc/raddb/modules/detail.log including configuration file /etc/raddb/modules/cache including configuration file /etc/raddb/modules/policy including configuration file /etc/raddb/modules/pap including configuration file /etc/raddb/modules/exec including configuration file /etc/raddb/modules/unix including configuration file /etc/raddb/modules/sqlcounter_expire_on_login including configuration file /etc/raddb/modules/always including configuration file /etc/raddb/modules/attr_filter including configuration file /etc/raddb/modules/mac2ip including configuration file /etc/raddb/modules/otp including configuration file /etc/raddb/modules/mac2vlan including configuration file /etc/raddb/modules/detail.example.com including configuration file /etc/raddb/modules/sradutmp including configuration file /etc/raddb/modules/smbpasswd including configuration file /etc/raddb/modules/radrelay including configuration file /etc/raddb/modules/rediswho including configuration file /etc/raddb/modules/inner-eap including configuration file /etc/raddb/modules/logintime including configuration file /etc/raddb/modules/linelog including configuration file /etc/raddb/modules/dynamic_clients including configuration file /etc/raddb/modules/perl including configuration file /etc/raddb/modules/echo including configuration file /etc/raddb/modules/radutmp including configuration file /etc/raddb/modules/checkval including configuration file /etc/raddb/modules/files including configuration file /etc/raddb/modules/mschap including configuration file /etc/raddb/modules/replicate including configuration file /etc/raddb/modules/expr including configuration file /etc/raddb/modules/expiration including configuration file /etc/raddb/modules/smsotp including configuration file /etc/raddb/modules/counter including configuration file /etc/raddb/modules/detail including configuration file /etc/raddb/modules/preprocess including configuration file /etc/raddb/modules/chap including configuration file /etc/raddb/eap.conf including configuration file /etc/raddb/sql.conf including configuration file /etc/raddb/sql/mysql/dialup.conf including configuration file /etc/raddb/sqlippool.conf including configuration file /etc/raddb/sql/mysql/ippool.conf including configuration file /etc/raddb/policy.conf including files in directory /etc/raddb/sites-enabled/ including configuration file /etc/raddb/sites-enabled/control-socket including configuration file /etc/raddb/sites-enabled/default including configuration file /etc/raddb/sites-enabled/inner-tunnel main { user = "radiusd" group = "radiusd" allow_core_dumps = no } including dictionary file /etc/raddb/dictionary 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 = yes log { stripped_names = yes auth = no auth_badpass = yes auth_goodpass = no } security { max_attributes = 200 reject_delay = 1 status_server = yes } } radiusd: #### Loading Realms and Home Servers #### realm other.test.net.nz { authhost = 127.0.0.1 accthost = 127.0.0.1 secret = s7f9876dg6sg85shd5s9 } realm test.net.nz { authhost = 127.0.0.1 accthost = 127.0.0.1 secret = s7f9876dg6sg85shd5s9 } radiusd: #### Loading Clients #### client localhost { ipaddr = 127.0.0.1 require_message_authenticator = no secret = "s7f9876dg6sg85shd5s9" nastype = "other" } client 10.11.127.229 { require_message_authenticator = no secret = "s7f9876dg6sg85shd5s9" } client 10.11.127.218 { require_message_authenticator = no secret = "s7f9876dg6sg85shd5s9" } radiusd: #### Instantiating modules #### instantiate { Module: Linked to module rlm_exec Module: Instantiating module "exec" from file /etc/raddb/modules/exec exec { wait = no input_pairs = "request" shell_escape = yes timeout = 10 } Module: Linked to module rlm_expr Module: Instantiating module "expr" from file /etc/raddb/modules/expr Module: Linked to module rlm_expiration Module: Instantiating module "expiration" from file /etc/raddb/modules/expiration expiration { reply-message = "Password Has Expired " } Module: Linked to module rlm_logintime Module: Instantiating module "logintime" from file /etc/raddb/modules/logintime logintime { reply-message = "You are calling outside your allowed timespan " minimum-timeout = 60 } } radiusd: #### Loading Virtual Servers #### server { # from file modules { Module: Creating Auth-Type = digest Module: Creating Post-Auth-Type = REJECT Module: Checking authenticate {...} for more modules to load Module: Linked to module rlm_pap Module: Instantiating module "pap" from file /etc/raddb/modules/pap pap { encryption_scheme = "auto" auto_header = no } Module: Linked to module rlm_chap Module: Instantiating module "chap" from file /etc/raddb/modules/chap Module: Linked to module rlm_mschap Module: Instantiating module "mschap" from file /etc/raddb/modules/mschap mschap { use_mppe = yes require_encryption = no require_strong = no with_ntdomain_hack = no allow_retry = yes } Module: Linked to module rlm_digest Module: Instantiating module "digest" from file /etc/raddb/modules/digest Module: Linked to module rlm_unix Module: Instantiating module "unix" from file /etc/raddb/modules/unix unix { radwtmp = "/var/log/radius/radwtmp" } Module: Linked to module rlm_eap Module: Instantiating module "eap" from file /etc/raddb/eap.conf eap { default_eap_type = "md5" timer_expire = 60 ignore_unknown_eap_types = no cisco_accounting_username_bug = no max_sessions = 1024 } Module: Linked to sub-module rlm_eap_md5 Module: Instantiating eap-md5 Module: Linked to sub-module rlm_eap_leap Module: Instantiating eap-leap Module: Linked to sub-module rlm_eap_gtc Module: Instantiating eap-gtc gtc { challenge = "Password: " auth_type = "PAP" } Module: Linked to sub-module rlm_eap_tls Module: Instantiating eap-tls tls { 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 = "whatever" dh_file = "/etc/raddb/certs/dh" fragment_size = 1024 include_length = yes check_crl = no cipher_list = "DEFAULT" ecdh_curve = "prime256v1" cache { enable = no 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 } } Module: Linked to sub-module rlm_eap_ttls Module: Instantiating eap-ttls ttls { default_eap_type = "md5" copy_request_to_tunnel = no use_tunneled_reply = no virtual_server = "inner-tunnel" include_length = yes } Module: Linked to sub-module rlm_eap_peap Module: Instantiating eap-peap peap { 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 } Module: Linked to sub-module rlm_eap_mschapv2 Module: Instantiating eap-mschapv2 mschapv2 { with_ntdomain_hack = no send_error = no } Module: Checking authorize {...} for more modules to load Module: Linked to module rlm_preprocess Module: Instantiating module "preprocess" from file /etc/raddb/modules/preprocess preprocess { huntgroups = "/etc/raddb/huntgroups" hints = "/etc/raddb/hints" with_ascend_hack = no ascend_channels_per_line = 23 with_ntdomain_hack = no with_specialix_jetstream_hack = no with_cisco_vsa_hack = no with_alvarion_vsa_hack = no } reading pairlist file /etc/raddb/huntgroups reading pairlist file /etc/raddb/hints Module: Linked to module rlm_realm Module: Instantiating module "suffix" from file /etc/raddb/modules/realm realm suffix { format = "suffix" delimiter = "@" ignore_default = no ignore_null = no } Module: Linked to module rlm_sql Module: Instantiating module "sql" from file /etc/raddb/sql.conf sql { driver = "rlm_sql_mysql" server = "localhost" port = "" login = "radius" password = "pqJdP6qa3sZPt76" radius_db = "cloudradius" read_groups = yes sqltrace = no sqltracefile = "/var/log/radius/sqltrace.sql" readclients = no deletestalesessions = yes num_sql_socks = 32 lifetime = 0 max_queries = 0 sql_user_name = "%{%{Stripped-User-Name}:-%{%{User-Name}:-DEFAULT}}" default_user_profile = "" nas_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" accounting_onoff_query = " UPDATE radacct SET acctstoptime = '%S', acctsessiontime = unix_timestamp('%S') - unix_timestamp(acctstarttime), acctterminatecause = '%{Acct-Terminate-Cause}', acctstopdelay = %{%{Acct-Delay-Time}:-0} WHERE acctstoptime IS NULL AND nasipaddress = '%{NAS-IP-Address}' AND acctstarttime <= '%S'" accounting_update_query = " UPDATE radacct SET framedipaddress = '%{Framed-IP-Address}', acctsessiontime = '%{%{Acct-Session-Time}:-0}', acctinputoctets = '%{%{Acct-Input-Gigawords}:-0}' << 32 | '%{%{Acct-Input-Octets}:-0}', acctoutputoctets = '%{%{Acct-Output-Gigawords}:-0}' << 32 | '%{%{Acct-Output-Octets}:-0}' WHERE acctsessionid = '%{Acct-Session-Id}' AND username = '%{SQL-User-Name}' AND nasipaddress = '%{NAS-IP-Address}'" accounting_update_query_alt = " INSERT INTO radacct (acctsessionid, acctuniqueid, username, realm, nasipaddress, nasportid, nasporttype, acctstarttime, acctsessiontime, acctauthentic, connectinfo_start, acctinputoctets, acctoutputoctets, calledstationid, callingstationid, servicetype, framedprotocol, framedipaddress, acctstartdelay, xascendsessionsvrkey) VALUES ('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}', '%{SQL-User-Name}', '%{Realm}', '%{NAS-IP-Address}', '%{NAS-Port}', '%{NAS-Port-Type}', DATE_SUB('%S', INTERVAL (%{%{Acct-Session-Time}:-0} + %{%{Acct-Delay-Time}:-0}) SECOND), '%{%{Acct-Session-Time}:-0}', '%{Acct-Authentic}', '', '%{%{Acct-Input-Gigawords}:-0}' << 32 | '%{%{Acct-Input-Octets}:-0}', '%{%{Acct-Output-Gigawords}:-0}' << 32 | '%{%{Acct-Output-Octets}:-0}', '%{Called-Station-Id}', '%{Calling-Station-Id}', '%{Service-Type}', '%{Framed-Protocol}', '%{Framed-IP-Address}', '0', '%{X-Ascend-Session-Svr-Key}')" accounting_start_query = " INSERT INTO radacct (acctsessionid, acctuniqueid, username, realm, nasipaddress, nasportid, nasporttype, acctstarttime, acctstoptime, acctsessiontime, acctauthentic, connectinfo_start, connectinfo_stop, acctinputoctets, acctoutputoctets, calledstationid, callingstationid, acctterminatecause, servicetype, framedprotocol, framedipaddress, acctstartdelay, acctstopdelay, xascendsessionsvrkey) VALUES ('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}', '%{SQL-User-Name}', '%{Realm}', '%{NAS-IP-Address}', '%{NAS-Port}', '%{NAS-Port-Type}', '%S', NULL, '0', '%{Acct-Authentic}', '%{Connect-Info}', '', '0', '0', '%{Called-Station-Id}', '%{Calling-Station-Id}', '', '%{Service-Type}', '%{Framed-Protocol}', '%{Framed-IP-Address}', '%{%{Acct-Delay-Time}:-0}', '0', '%{X-Ascend-Session-Svr-Key}')" accounting_start_query_alt = " UPDATE radacct SET acctstarttime = '%S', acctstartdelay = '%{%{Acct-Delay-Time}:-0}', connectinfo_start = '%{Connect-Info}' WHERE acctsessionid = '%{Acct-Session-Id}' AND username = '%{SQL-User-Name}' AND nasipaddress = '%{NAS-IP-Address}'" accounting_stop_query = " UPDATE radacct SET acctstoptime = '%S', acctsessiontime = '%{%{Acct-Session-Time}:-0}', acctinputoctets = '%{%{Acct-Input-Gigawords}:-0}' << 32 | '%{%{Acct-Input-Octets}:-0}', acctoutputoctets = '%{%{Acct-Output-Gigawords}:-0}' << 32 | '%{%{Acct-Output-Octets}:-0}', acctterminatecause = '%{Acct-Terminate-Cause}', acctstopdelay = '%{%{Acct-Delay-Time}:-0}', connectinfo_stop = '%{Connect-Info}' WHERE acctsessionid = '%{Acct-Session-Id}' AND username = '%{SQL-User-Name}' AND nasipaddress = '%{NAS-IP-Address}'" accounting_stop_query_alt = " INSERT INTO radacct (acctsessionid, acctuniqueid, username, realm, nasipaddress, nasportid, nasporttype, acctstarttime, acctstoptime, acctsessiontime, acctauthentic, connectinfo_start, connectinfo_stop, acctinputoctets, acctoutputoctets, calledstationid, callingstationid, acctterminatecause, servicetype, framedprotocol, framedipaddress, acctstartdelay, acctstopdelay) VALUES ('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}', '%{SQL-User-Name}', '%{Realm}', '%{NAS-IP-Address}', '%{NAS-Port}', '%{NAS-Port-Type}', DATE_SUB('%S', INTERVAL (%{%{Acct-Session-Time}:-0} + %{%{Acct-Delay-Time}:-0}) SECOND), '%S', '%{%{Acct-Session-Time}:-0}', '%{Acct-Authentic}', '', '%{Connect-Info}', '%{%{Acct-Input-Gigawords}:-0}' << 32 | '%{%{Acct-Input-Octets}:-0}', '%{%{Acct-Output-Gigawords}:-0}' << 32 | '%{%{Acct-Output-Octets}:-0}', '%{Called-Station-Id}', '%{Calling-Station-Id}', '%{Acct-Terminate-Cause}', '%{Service-Type}', '%{Framed-Protocol}', '%{Framed-IP-Address}', '0', '%{%{Acct-Delay-Time}:-0}')" group_membership_query = "SELECT groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority" connect_failure_retry_delay = 60 simul_count_query = "" simul_verify_query = "SELECT radacctid, acctsessionid, username, nasipaddress, nasportid, framedipaddress, callingstationid, framedprotocol FROM radacct WHERE username = '%{SQL-User-Name}' AND acctstoptime IS NULL" postauth_query = "INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '%{User-Name}', '%{%{User-Password}:-%{Chap-Password}}', '%{reply:Packet-Type}', '%S')" safe-characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /" } rlm_sql (sql): Driver rlm_sql_mysql (module rlm_sql_mysql) loaded and linked rlm_sql (sql): Attempting to connect to radius@localhost:/cloudradius rlm_sql (sql): starting 0 rlm_sql (sql): Attempting to connect rlm_sql_mysql #0 rlm_sql_mysql: Starting connect to MySQL server for #0 rlm_sql (sql): Connected new DB handle, #0 rlm_sql (sql): starting 1 rlm_sql (sql): Attempting to connect rlm_sql_mysql #1 rlm_sql_mysql: Starting connect to MySQL server for #1 rlm_sql (sql): Connected new DB handle, #1 rlm_sql (sql): starting 2 rlm_sql (sql): Attempting to connect rlm_sql_mysql #2 rlm_sql_mysql: Starting connect to MySQL server for #2 rlm_sql (sql): Connected new DB handle, #2 rlm_sql (sql): starting 3 rlm_sql (sql): Attempting to connect rlm_sql_mysql #3 rlm_sql_mysql: Starting connect to MySQL server for #3 rlm_sql (sql): Connected new DB handle, #3 rlm_sql (sql): starting 4 rlm_sql (sql): Attempting to connect rlm_sql_mysql #4 rlm_sql_mysql: Starting connect to MySQL server for #4 rlm_sql (sql): Connected new DB handle, #4 rlm_sql (sql): starting 5 rlm_sql (sql): Attempting to connect rlm_sql_mysql #5 rlm_sql_mysql: Starting connect to MySQL server for #5 rlm_sql (sql): Connected new DB handle, #5 rlm_sql (sql): starting 6 rlm_sql (sql): Attempting to connect rlm_sql_mysql #6 rlm_sql_mysql: Starting connect to MySQL server for #6 rlm_sql (sql): Connected new DB handle, #6 rlm_sql (sql): starting 7 rlm_sql (sql): Attempting to connect rlm_sql_mysql #7 rlm_sql_mysql: Starting connect to MySQL server for #7 rlm_sql (sql): Connected new DB handle, #7 rlm_sql (sql): starting 8 rlm_sql (sql): Attempting to connect rlm_sql_mysql #8 rlm_sql_mysql: Starting connect to MySQL server for #8 rlm_sql (sql): Connected new DB handle, #8 rlm_sql (sql): starting 9 rlm_sql (sql): Attempting to connect rlm_sql_mysql #9 rlm_sql_mysql: Starting connect to MySQL server for #9 rlm_sql (sql): Connected new DB handle, #9 rlm_sql (sql): starting 10 rlm_sql (sql): Attempting to connect rlm_sql_mysql #10 rlm_sql_mysql: Starting connect to MySQL server for #10 rlm_sql (sql): Connected new DB handle, #10 rlm_sql (sql): starting 11 rlm_sql (sql): Attempting to connect rlm_sql_mysql #11 rlm_sql_mysql: Starting connect to MySQL server for #11 rlm_sql (sql): Connected new DB handle, #11 rlm_sql (sql): starting 12 rlm_sql (sql): Attempting to connect rlm_sql_mysql #12 rlm_sql_mysql: Starting connect to MySQL server for #12 rlm_sql (sql): Connected new DB handle, #12 rlm_sql (sql): starting 13 rlm_sql (sql): Attempting to connect rlm_sql_mysql #13 rlm_sql_mysql: Starting connect to MySQL server for #13 rlm_sql (sql): Connected new DB handle, #13 rlm_sql (sql): starting 14 rlm_sql (sql): Attempting to connect rlm_sql_mysql #14 rlm_sql_mysql: Starting connect to MySQL server for #14 rlm_sql (sql): Connected new DB handle, #14 rlm_sql (sql): starting 15 rlm_sql (sql): Attempting to connect rlm_sql_mysql #15 rlm_sql_mysql: Starting connect to MySQL server for #15 rlm_sql (sql): Connected new DB handle, #15 rlm_sql (sql): starting 16 rlm_sql (sql): Attempting to connect rlm_sql_mysql #16 rlm_sql_mysql: Starting connect to MySQL server for #16 rlm_sql (sql): Connected new DB handle, #16 rlm_sql (sql): starting 17 rlm_sql (sql): Attempting to connect rlm_sql_mysql #17 rlm_sql_mysql: Starting connect to MySQL server for #17 rlm_sql (sql): Connected new DB handle, #17 rlm_sql (sql): starting 18 rlm_sql (sql): Attempting to connect rlm_sql_mysql #18 rlm_sql_mysql: Starting connect to MySQL server for #18 rlm_sql (sql): Connected new DB handle, #18 rlm_sql (sql): starting 19 rlm_sql (sql): Attempting to connect rlm_sql_mysql #19 rlm_sql_mysql: Starting connect to MySQL server for #19 rlm_sql (sql): Connected new DB handle, #19 rlm_sql (sql): starting 20 rlm_sql (sql): Attempting to connect rlm_sql_mysql #20 rlm_sql_mysql: Starting connect to MySQL server for #20 rlm_sql (sql): Connected new DB handle, #20 rlm_sql (sql): starting 21 rlm_sql (sql): Attempting to connect rlm_sql_mysql #21 rlm_sql_mysql: Starting connect to MySQL server for #21 rlm_sql (sql): Connected new DB handle, #21 rlm_sql (sql): starting 22 rlm_sql (sql): Attempting to connect rlm_sql_mysql #22 rlm_sql_mysql: Starting connect to MySQL server for #22 rlm_sql (sql): Connected new DB handle, #22 rlm_sql (sql): starting 23 rlm_sql (sql): Attempting to connect rlm_sql_mysql #23 rlm_sql_mysql: Starting connect to MySQL server for #23 rlm_sql (sql): Connected new DB handle, #23 rlm_sql (sql): starting 24 rlm_sql (sql): Attempting to connect rlm_sql_mysql #24 rlm_sql_mysql: Starting connect to MySQL server for #24 rlm_sql (sql): Connected new DB handle, #24 rlm_sql (sql): starting 25 rlm_sql (sql): Attempting to connect rlm_sql_mysql #25 rlm_sql_mysql: Starting connect to MySQL server for #25 rlm_sql (sql): Connected new DB handle, #25 rlm_sql (sql): starting 26 rlm_sql (sql): Attempting to connect rlm_sql_mysql #26 rlm_sql_mysql: Starting connect to MySQL server for #26 rlm_sql (sql): Connected new DB handle, #26 rlm_sql (sql): starting 27 rlm_sql (sql): Attempting to connect rlm_sql_mysql #27 rlm_sql_mysql: Starting connect to MySQL server for #27 rlm_sql (sql): Connected new DB handle, #27 rlm_sql (sql): starting 28 rlm_sql (sql): Attempting to connect rlm_sql_mysql #28 rlm_sql_mysql: Starting connect to MySQL server for #28 rlm_sql (sql): Connected new DB handle, #28 rlm_sql (sql): starting 29 rlm_sql (sql): Attempting to connect rlm_sql_mysql #29 rlm_sql_mysql: Starting connect to MySQL server for #29 rlm_sql (sql): Connected new DB handle, #29 rlm_sql (sql): starting 30 rlm_sql (sql): Attempting to connect rlm_sql_mysql #30 rlm_sql_mysql: Starting connect to MySQL server for #30 rlm_sql (sql): Connected new DB handle, #30 rlm_sql (sql): starting 31 rlm_sql (sql): Attempting to connect rlm_sql_mysql #31 rlm_sql_mysql: Starting connect to MySQL server for #31 rlm_sql (sql): Connected new DB handle, #31 Module: Checking preacct {...} for more modules to load Module: Linked to module rlm_acct_unique Module: Instantiating module "acct_unique" from file /etc/raddb/modules/acct_unique acct_unique { key = "User-Name, Acct-Session-Id, NAS-IP-Address, NAS-Identifier, NAS-Port" } Module: Linked to module rlm_files Module: Instantiating module "files" from file /etc/raddb/modules/files files { usersfile = "/etc/raddb/users" acctusersfile = "/etc/raddb/acct_users" preproxy_usersfile = "/etc/raddb/preproxy_users" compat = "no" } reading pairlist file /etc/raddb/users reading pairlist file /etc/raddb/acct_users reading pairlist file /etc/raddb/preproxy_users Module: Checking accounting {...} for more modules to load Module: Linked to module rlm_sqlippool Module: Instantiating module "sqlippool" from file /etc/raddb/sqlippool.conf sqlippool { sql-instance-name = "sql" lease-duration = 1200 pool-name = "" allocate-begin = "START TRANSACTION" allocate-clear = "UPDATE radippool SET nasipaddress = '', pool_key = 0, callingstationid = '', username = '', expiry_time = NULL WHERE expiry_time <= NOW() - INTERVAL 1 SECOND AND nasipaddress = '%{Nas-IP-Address}'" allocate-find = "SELECT framedipaddress FROM radippool WHERE pool_name = '%{control:Pool-Name}' AND (expiry_time < NOW() OR expiry_time IS NULL) ORDER BY (username <> '%{User-Name}'), (callingstationid <> '%{Calling-Station-Id}'), expiry_time LIMIT 1 FOR UPDATE" allocate-update = "UPDATE radippool SET nasipaddress = '%{NAS-IP-Address}', pool_key = '%{NAS-Port}', callingstationid = '%{Calling-Station-Id}', username = '%{User-Name}', expiry_time = NOW() + INTERVAL 1200 SECOND WHERE framedipaddress = '%I' AND expiry_time IS NULL" allocate-commit = "COMMIT" allocate-rollback = "ROLLBACK" pool-check = "SELECT id FROM radippool WHERE pool_name='%{control:Pool-Name}' LIMIT 1" start-begin = "START TRANSACTION" start-update = "UPDATE radippool SET expiry_time = NOW() + INTERVAL 1200 SECOND WHERE nasipaddress = '%{NAS-IP-Address}' AND pool_key = '%{NAS-Port}' AND username = '%{User-Name}' AND callingstationid = '%{Calling-Station-Id}' AND framedipaddress = '%{Framed-IP-Address}'" start-commit = "COMMIT" start-rollback = "ROLLBACK" alive-begin = "START TRANSACTION" alive-update = "UPDATE radippool SET expiry_time = NOW() + INTERVAL 1200 SECOND WHERE nasipaddress = '%{Nas-IP-Address}' AND pool_key = '%{NAS-Port}' AND username = '%{User-Name}' AND callingstationid = '%{Calling-Station-Id}' AND framedipaddress = '%{Framed-IP-Address}'" alive-commit = "COMMIT" alive-rollback = "ROLLBACK" stop-begin = "START TRANSACTION" stop-clear = "UPDATE radippool SET nasipaddress = '', pool_key = 0, callingstationid = '', username = '', expiry_time = NULL WHERE nasipaddress = '%{Nas-IP-Address}' AND pool_key = '%{NAS-Port}' AND username = '%{User-Name}' AND callingstationid = '%{Calling-Station-Id}' AND framedipaddress = '%{Framed-IP-Address}'" stop-commit = "COMMIT" stop-rollback = "ROLLBACK" on-begin = "START TRANSACTION" on-clear = "UPDATE radippool SET nasipaddress = '', pool_key = 0, callingstationid = '', username = '', expiry_time = NULL WHERE nasipaddress = '%{Nas-IP-Address}'" on-commit = "COMMIT" on-rollback = "ROLLBACK" off-begin = "START TRANSACTION" off-clear = "UPDATE radippool SET nasipaddress = '', pool_key = 0, callingstationid = '', username = '', expiry_time = NULL WHERE nasipaddress = '%{Nas-IP-Address}'" off-commit = "COMMIT" off-rollback = "ROLLBACK" sqlippool_log_exists = "Existing IP: %{reply:Framed-IP-Address} (did %{Called-Station-Id} cli %{Calling-Station-Id} port %{NAS-Port} user %{User-Name})" sqlippool_log_success = "Allocated IP: %{reply:Framed-IP-Address} from %{control:Pool-Name} (did %{Called-Station-Id} cli %{Calling-Station-Id} port %{NAS-Port} user %{User-Name})" sqlippool_log_clear = "Released IP %{Framed-IP-Address} (did %{Called-Station-Id} cli %{Calling-Station-Id} user %{User-Name})" sqlippool_log_failed = "IP Allocation FAILED from %{control:Pool-Name} (did %{Called-Station-Id} cli %{Calling-Station-Id} port %{NAS-Port} user %{User-Name})" sqlippool_log_nopool = "No Pool-Name defined (did %{Called-Station-Id} cli %{Calling-Station-Id} port %{NAS-Port} user %{User-Name})" defaultpool = "main_pool" } Module: Linked to module rlm_always Module: Instantiating module "ok" from file /etc/raddb/modules/always always ok { rcode = "ok" simulcount = 0 mpp = no } Module: Linked to module rlm_attr_filter Module: Instantiating module "attr_filter.accounting_response" from file /etc/raddb/modules/attr_filter attr_filter attr_filter.accounting_response { attrsfile = "/etc/raddb/attrs.accounting_response" key = "%{User-Name}" relaxed = no } reading pairlist file /etc/raddb/attrs.accounting_response Module: Checking session {...} for more modules to load Module: Linked to module rlm_radutmp Module: Instantiating module "radutmp" from file /etc/raddb/modules/radutmp radutmp { filename = "/var/log/radius/radutmp" username = "%{User-Name}" case_sensitive = yes check_with_nas = yes perm = 384 callerid = yes } Module: Checking post-proxy {...} for more modules to load Module: Checking post-auth {...} for more modules to load Module: Instantiating module "attr_filter.access_reject" from file /etc/raddb/modules/attr_filter attr_filter attr_filter.access_reject { attrsfile = "/etc/raddb/attrs.access_reject" key = "%{User-Name}" relaxed = no } reading pairlist file /etc/raddb/attrs.access_reject } # modules } # server server inner-tunnel { # from file /etc/raddb/sites-enabled/inner-tunnel modules { Module: Checking authenticate {...} for more modules to load Module: Checking authorize {...} for more modules to load Module: Checking session {...} for more modules to load Module: Checking post-proxy {...} for more modules to load Module: Checking post-auth {...} for more modules to load } # modules } # server radiusd: #### Opening IP addresses and Ports #### listen { type = "auth" ipaddr = * port = 0 } listen { type = "acct" ipaddr = * port = 0 } listen { type = "control" listen { socket = "/var/run/radiusd/radiusd.sock" } } listen { type = "auth" ipaddr = 127.0.0.1 port = 18120 } Listening on authentication address * port 1812 Listening on accounting address * port 1813 Listening on command file /var/run/radiusd/radiusd.sock Listening on authentication address 127.0.0.1 port 18120 as server inner-tunnel Listening on proxy address * port 1814 Ready to process requests. rad_recv: Access-Request packet from host 10.11.127.229 port 46224, id=31, length=276 Service-Type = Framed-User Framed-Protocol = PPP NAS-Port = 15729457 NAS-Port-Type = Ethernet User-Name = "testlane5@test.net.nz" Calling-Station-Id = "02:24:83:47:95:AB" Called-Station-Id = "tech.test.net.nz" NAS-Port-Id = "eoip-timarutech" MS-CHAP-Domain = "test.net.nz" MS-CHAP-Challenge = 0x1f3993056e4dacd5d7112a34d9d97078 MS-CHAP2-Response = 0x0100eb3b8b7818917c46039413a48a7a52780000000000000000246c4cef8fc251c4ed3fccc26c71a0b1242e0d678989479d NAS-Identifier = "tech.test.net.nz" Mikrotik-Realm = "test.net.nz" NAS-IP-Address = 10.11.127.229 # Executing section authorize from file /etc/raddb/sites-enabled/default +group authorize { ++[preprocess] = ok ++[chap] = noop [mschap] Found MS-CHAP attributes. Setting 'Auth-Type = mschap' ++[mschap] = ok ++[digest] = noop [suffix] Looking up realm "test.net.nz" for User-Name = "testlane5@test.net.nz" [suffix] Found realm "test.net.nz" [suffix] Adding Stripped-User-Name = "testlane5" [suffix] Adding Realm = "test.net.nz" [suffix] Proxying request from user testlane5 to realm test.net.nz [suffix] Preparing to proxy authentication request to realm "test.net.nz" ++[suffix] = updated [eap] No EAP-Message, not doing EAP ++[eap] = noop [sql] expand: %{Stripped-User-Name} -> testlane5 [sql] expand: %{%{Stripped-User-Name}:-%{%{User-Name}:-DEFAULT}} -> testlane5 [sql] sql_set_user escaped user --> 'testlane5' rlm_sql (sql): Reserving sql socket id: 31 [sql] expand: SELECT id, username, attribute, value, op FROM radcheck WHERE username = '%{SQL-User-Name}' ORDER BY id -> SELECT id, username, attribute, value, op FROM radcheck WHERE username = 'testlane5' ORDER BY id [sql] User found in radcheck table [sql] expand: SELECT id, username, attribute, value, op FROM radreply WHERE username = '%{SQL-User-Name}' ORDER BY id -> SELECT id, username, attribute, value, op FROM radreply WHERE username = 'testlane5' ORDER BY id [sql] expand: SELECT groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority -> SELECT groupname FROM radusergroup WHERE username = 'testlane5' ORDER BY priority [sql] expand: SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = '%{Sql-Group}' ORDER BY id -> SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = 'default' ORDER BY id [sql] User found in group default [sql] expand: SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = '%{Sql-Group}' ORDER BY id -> SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = 'default' ORDER BY id rlm_sql (sql): Released sql socket id: 31 ++[sql] = ok ++[expiration] = noop ++[logintime] = noop ++[pap] = noop ++? if (!control:Auth-Type) ? Evaluating !(control:Auth-Type) -> FALSE ++? if (!control:Auth-Type) -> FALSE +} # group authorize = updated WARNING: Empty pre-proxy section. Using default return values. Sending Access-Request of id 71 to 127.0.0.1 port 1812 Service-Type = Framed-User Framed-Protocol = PPP NAS-Port = 15729457 NAS-Port-Type = Ethernet User-Name = "testlane5" Calling-Station-Id = "02:24:83:47:95:AB" Called-Station-Id = "tech.test.net.nz" NAS-Port-Id = "eoip-timarutech" MS-CHAP-Domain = "test.net.nz" MS-CHAP-Challenge = 0x1f3993056e4dacd5d7112a34d9d97078 MS-CHAP2-Response = 0x0100eb3b8b7818917c46039413a48a7a52780000000000000000246c4cef8fc251c4ed3fccc26c71a0b1242e0d678989479d NAS-Identifier = "tech.test.net.nz" Mikrotik-Realm = "test.net.nz" NAS-IP-Address = 10.11.127.229 Proxy-State = 0x3331 Proxying request 0 to home server 127.0.0.1 port 1812 Sending Access-Request of id 71 to 127.0.0.1 port 1812 Service-Type = Framed-User Framed-Protocol = PPP NAS-Port = 15729457 NAS-Port-Type = Ethernet User-Name = "testlane5" Calling-Station-Id = "02:24:83:47:95:AB" Called-Station-Id = "tech.test.net.nz" NAS-Port-Id = "eoip-timarutech" MS-CHAP-Domain = "test.net.nz" MS-CHAP-Challenge = 0x1f3993056e4dacd5d7112a34d9d97078 MS-CHAP2-Response = 0x0100eb3b8b7818917c46039413a48a7a52780000000000000000246c4cef8fc251c4ed3fccc26c71a0b1242e0d678989479d NAS-Identifier = "tech.test.net.nz" Mikrotik-Realm = "test.net.nz" NAS-IP-Address = 10.11.127.229 Proxy-State = 0x3331 Going to the next request Waking up in 0.9 seconds. rad_recv: Access-Request packet from host 127.0.0.1 port 1814, id=71, length=267 Service-Type = Framed-User Framed-Protocol = PPP NAS-Port = 15729457 NAS-Port-Type = Ethernet User-Name = "testlane5" Calling-Station-Id = "02:24:83:47:95:AB" Called-Station-Id = "tech.test.net.nz" NAS-Port-Id = "eoip-timarutech" MS-CHAP-Domain = "test.net.nz" MS-CHAP-Challenge = 0x1f3993056e4dacd5d7112a34d9d97078 MS-CHAP2-Response = 0x0100eb3b8b7818917c46039413a48a7a52780000000000000000246c4cef8fc251c4ed3fccc26c71a0b1242e0d678989479d NAS-Identifier = "tech.test.net.nz" Mikrotik-Realm = "test.net.nz" NAS-IP-Address = 10.11.127.229 Proxy-State = 0x3331 # Executing section authorize from file /etc/raddb/sites-enabled/default +group authorize { ++[preprocess] = ok ++[chap] = noop [mschap] Found MS-CHAP attributes. Setting 'Auth-Type = mschap' ++[mschap] = ok ++[digest] = noop [suffix] No '@' in User-Name = "testlane5", looking up realm NULL [suffix] No such realm "NULL" ++[suffix] = noop [eap] No EAP-Message, not doing EAP ++[eap] = noop [sql] expand: %{Stripped-User-Name} -> [sql] ... expanding second conditional [sql] expand: %{User-Name} -> testlane5 [sql] expand: %{%{User-Name}:-DEFAULT} -> testlane5 [sql] expand: %{%{Stripped-User-Name}:-%{%{User-Name}:-DEFAULT}} -> testlane5 [sql] sql_set_user escaped user --> 'testlane5' rlm_sql (sql): Reserving sql socket id: 30 [sql] expand: SELECT id, username, attribute, value, op FROM radcheck WHERE username = '%{SQL-User-Name}' ORDER BY id -> SELECT id, username, attribute, value, op FROM radcheck WHERE username = 'testlane5' ORDER BY id [sql] User found in radcheck table [sql] expand: SELECT id, username, attribute, value, op FROM radreply WHERE username = '%{SQL-User-Name}' ORDER BY id -> SELECT id, username, attribute, value, op FROM radreply WHERE username = 'testlane5' ORDER BY id [sql] expand: SELECT groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority -> SELECT groupname FROM radusergroup WHERE username = 'testlane5' ORDER BY priority [sql] expand: SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = '%{Sql-Group}' ORDER BY id -> SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = 'default' ORDER BY id [sql] User found in group default [sql] expand: SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = '%{Sql-Group}' ORDER BY id -> SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = 'default' ORDER BY id rlm_sql (sql): Released sql socket id: 30 ++[sql] = ok ++[expiration] = noop ++[logintime] = noop [pap] WARNING: Auth-Type already set. Not setting to PAP ++[pap] = noop ++? if (!control:Auth-Type) ? Evaluating !(control:Auth-Type) -> FALSE ++? if (!control:Auth-Type) -> FALSE +} # group authorize = ok Found Auth-Type = MSCHAP # Executing group from file /etc/raddb/sites-enabled/default +group MS-CHAP { [mschap] Creating challenge hash with username: testlane5 [mschap] Client is using MS-CHAPv2 for testlane5, we need NT-Password [mschap] FAILED: MS-CHAP2-Response is incorrect ++[mschap] = reject +} # group MS-CHAP = reject Failed to authenticate the user. Using Post-Auth-Type REJECT # Executing group from file /etc/raddb/sites-enabled/default +group REJECT { [sql] expand: %{Stripped-User-Name} -> [sql] ... expanding second conditional [sql] expand: %{User-Name} -> testlane5 [sql] expand: %{%{User-Name}:-DEFAULT} -> testlane5 [sql] expand: %{%{Stripped-User-Name}:-%{%{User-Name}:-DEFAULT}} -> testlane5 [sql] sql_set_user escaped user --> 'testlane5' [sql] expand: %{User-Password} -> [sql] ... expanding second conditional [sql] expand: %{Chap-Password} -> [sql] expand: INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '%{User-Name}', '%{%{User-Password}:-%{Chap-Password}}', '%{reply:Packet-Type}', '%S') -> INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( 'testlane5', '', 'Access-Reject', '2019-05-19 20:05:11') rlm_sql (sql) in sql_postauth: query is INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( 'testlane5', '', 'Access-Reject', '2019-05-19 20:05:11') rlm_sql (sql): Reserving sql socket id: 29 rlm_sql (sql): Released sql socket id: 29 ++[sql] = ok [attr_filter.access_reject] expand: %{User-Name} -> testlane5 attr_filter: Matched entry DEFAULT at line 11 ++[attr_filter.access_reject] = updated +} # group REJECT = updated Delaying reject of request 1 for 1 seconds Going to the next request Waking up in 0.9 seconds. rad_recv: Access-Request packet from host 10.11.127.229 port 46224, id=31, length=276 Sending duplicate proxied request to home server 127.0.0.1 port 1812 - ID: 71 Sending Access-Request of id 71 to 127.0.0.1 port 1812 Service-Type = Framed-User Framed-Protocol = PPP NAS-Port = 15729457 NAS-Port-Type = Ethernet User-Name = "testlane5" Calling-Station-Id = "02:24:83:47:95:AB" Called-Station-Id = "tech.test.net.nz" NAS-Port-Id = "eoip-timarutech" MS-CHAP-Domain = "test.net.nz" MS-CHAP-Challenge = 0x1f3993056e4dacd5d7112a34d9d97078 MS-CHAP2-Response = 0x0100eb3b8b7818917c46039413a48a7a52780000000000000000246c4cef8fc251c4ed3fccc26c71a0b1242e0d678989479d NAS-Identifier = "tech.test.net.nz" Mikrotik-Realm = "test.net.nz" NAS-IP-Address = 10.11.127.229 Proxy-State = 0x3331 Waking up in 0.6 seconds. rad_recv: Access-Request packet from host 127.0.0.1 port 1814, id=71, length=267 Waiting to send Access-Reject to client localhost port 1814 - ID: 71 Waking up in 0.6 seconds. rad_recv: Access-Request packet from host 10.11.127.229 port 46224, id=31, length=276 Sending duplicate proxied request to home server 127.0.0.1 port 1812 - ID: 71 Sending Access-Request of id 71 to 127.0.0.1 port 1812 Service-Type = Framed-User Framed-Protocol = PPP NAS-Port = 15729457 NAS-Port-Type = Ethernet User-Name = "testlane5" Calling-Station-Id = "02:24:83:47:95:AB" Called-Station-Id = "tech.test.net.nz" NAS-Port-Id = "eoip-timarutech" MS-CHAP-Domain = "test.net.nz" MS-CHAP-Challenge = 0x1f3993056e4dacd5d7112a34d9d97078 MS-CHAP2-Response = 0x0100eb3b8b7818917c46039413a48a7a52780000000000000000246c4cef8fc251c4ed3fccc26c71a0b1242e0d678989479d NAS-Identifier = "tech.test.net.nz" Mikrotik-Realm = "test.net.nz" NAS-IP-Address = 10.11.127.229 Proxy-State = 0x3331 Waking up in 0.3 seconds. rad_recv: Access-Request packet from host 127.0.0.1 port 1814, id=71, length=267 Waiting to send Access-Reject to client localhost port 1814 - ID: 71 Waking up in 0.3 seconds. Sending delayed reject for request 1 Sending Access-Reject of id 71 to 127.0.0.1 port 1814 MS-CHAP-Error = "\001E=691 R=1" Proxy-State = 0x3331 Waking up in 4.9 seconds. rad_recv: Access-Reject packet from host 127.0.0.1 port 1812, id=71, length=42 MS-CHAP-Error = "\001E=691 R=1" Proxy-State = 0x3331 # Executing section post-proxy from file /etc/raddb/sites-enabled/default +group post-proxy { [eap] No pre-existing handler found ++[eap] = noop +} # group post-proxy = noop Using Post-Auth-Type REJECT # Executing group from file /etc/raddb/sites-enabled/default +group REJECT { [sql] expand: %{Stripped-User-Name} -> testlane5 [sql] expand: %{%{Stripped-User-Name}:-%{%{User-Name}:-DEFAULT}} -> testlane5 [sql] sql_set_user escaped user --> 'testlane5' [sql] expand: %{User-Password} -> [sql] ... expanding second conditional [sql] expand: %{Chap-Password} -> [sql] expand: INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '%{User-Name}', '%{%{User-Password}:-%{Chap-Password}}', '%{reply:Packet-Type}', '%S') -> INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( 'testlane5@test.net.nz', '', 'Access-Reject', '2019-05-19 20:05:11') rlm_sql (sql) in sql_postauth: query is INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( 'testlane5@test.net.nz', '', 'Access-Reject', '2019-05-19 20:05:11') rlm_sql (sql): Reserving sql socket id: 28 rlm_sql (sql): Released sql socket id: 28 ++[sql] = ok [attr_filter.access_reject] expand: %{User-Name} -> testlane5@test.net.nz attr_filter: Matched entry DEFAULT at line 11 ++[attr_filter.access_reject] = updated +} # group REJECT = updated Sending Access-Reject of id 31 to 10.11.127.229 port 46224 MS-CHAP-Error = "\001E=691 R=1" Finished request 0. Going to the next request Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 10.11.127.229 port 58794, id=32, length=276 Service-Type = Framed-User Framed-Protocol = PPP NAS-Port = 15729458 NAS-Port-Type = Ethernet User-Name = "testlane5@test.net.nz" Calling-Station-Id = "02:24:83:47:95:AB" Called-Station-Id = "tech.test.net.nz" NAS-Port-Id = "eoip-timarutech" MS-CHAP-Domain = "test.net.nz" MS-CHAP-Challenge = 0x8cfad6f1df5918ab44bcca7d4fd0eb9d MS-CHAP2-Response = 0x01007b8394b86094fb4bd086c3e8183f2e1b00000000000000007e68546c2b8eed73be5a12f8cb5175ab4cbedfa2aec45d2b NAS-Identifier = "tech.test.net.nz" Mikrotik-Realm = "test.net.nz" NAS-IP-Address = 10.11.127.229 # Executing section authorize from file /etc/raddb/sites-enabled/default +group authorize { ++[preprocess] = ok ++[chap] = noop [mschap] Found MS-CHAP attributes. Setting 'Auth-Type = mschap' ++[mschap] = ok ++[digest] = noop [suffix] Looking up realm "test.net.nz" for User-Name = "testlane5@test.net.nz" [suffix] Found realm "test.net.nz" [suffix] Adding Stripped-User-Name = "testlane5" [suffix] Adding Realm = "test.net.nz" [suffix] Proxying request from user testlane5 to realm test.net.nz [suffix] Preparing to proxy authentication request to realm "test.net.nz" ++[suffix] = updated [eap] No EAP-Message, not doing EAP ++[eap] = noop [sql] expand: %{Stripped-User-Name} -> testlane5 [sql] expand: %{%{Stripped-User-Name}:-%{%{User-Name}:-DEFAULT}} -> testlane5 [sql] sql_set_user escaped user --> 'testlane5' rlm_sql (sql): Reserving sql socket id: 27 [sql] expand: SELECT id, username, attribute, value, op FROM radcheck WHERE username = '%{SQL-User-Name}' ORDER BY id -> SELECT id, username, attribute, value, op FROM radcheck WHERE username = 'testlane5' ORDER BY id [sql] User found in radcheck table [sql] expand: SELECT id, username, attribute, value, op FROM radreply WHERE username = '%{SQL-User-Name}' ORDER BY id -> SELECT id, username, attribute, value, op FROM radreply WHERE username = 'testlane5' ORDER BY id [sql] expand: SELECT groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority -> SELECT groupname FROM radusergroup WHERE username = 'testlane5' ORDER BY priority [sql] expand: SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = '%{Sql-Group}' ORDER BY id -> SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = 'default' ORDER BY id [sql] User found in group default [sql] expand: SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = '%{Sql-Group}' ORDER BY id -> SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = 'default' ORDER BY id rlm_sql (sql): Released sql socket id: 27 ++[sql] = ok ++[expiration] = noop ++[logintime] = noop ++[pap] = noop ++? if (!control:Auth-Type) ? Evaluating !(control:Auth-Type) -> FALSE ++? if (!control:Auth-Type) -> FALSE +} # group authorize = updated WARNING: Empty pre-proxy section. Using default return values. Sending Access-Request of id 116 to 127.0.0.1 port 1812 Service-Type = Framed-User Framed-Protocol = PPP NAS-Port = 15729458 NAS-Port-Type = Ethernet User-Name = "testlane5" Calling-Station-Id = "02:24:83:47:95:AB" Called-Station-Id = "tech.test.net.nz" NAS-Port-Id = "eoip-timarutech" MS-CHAP-Domain = "test.net.nz" MS-CHAP-Challenge = 0x8cfad6f1df5918ab44bcca7d4fd0eb9d MS-CHAP2-Response = 0x01007b8394b86094fb4bd086c3e8183f2e1b00000000000000007e68546c2b8eed73be5a12f8cb5175ab4cbedfa2aec45d2b NAS-Identifier = "tech.test.net.nz" Mikrotik-Realm = "test.net.nz" NAS-IP-Address = 10.11.127.229 Proxy-State = 0x3332 Proxying request 2 to home server 127.0.0.1 port 1812 Sending Access-Request of id 116 to 127.0.0.1 port 1812 Service-Type = Framed-User Framed-Protocol = PPP NAS-Port = 15729458 NAS-Port-Type = Ethernet User-Name = "testlane5" Calling-Station-Id = "02:24:83:47:95:AB" Called-Station-Id = "tech.test.net.nz" NAS-Port-Id = "eoip-timarutech" MS-CHAP-Domain = "test.net.nz" MS-CHAP-Challenge = 0x8cfad6f1df5918ab44bcca7d4fd0eb9d MS-CHAP2-Response = 0x01007b8394b86094fb4bd086c3e8183f2e1b00000000000000007e68546c2b8eed73be5a12f8cb5175ab4cbedfa2aec45d2b NAS-Identifier = "tech.test.net.nz" Mikrotik-Realm = "test.net.nz" NAS-IP-Address = 10.11.127.229 Proxy-State = 0x3332 Going to the next request Waking up in 0.9 seconds. rad_recv: Access-Request packet from host 127.0.0.1 port 1814, id=116, length=267 Service-Type = Framed-User Framed-Protocol = PPP NAS-Port = 15729458 NAS-Port-Type = Ethernet User-Name = "testlane5" Calling-Station-Id = "02:24:83:47:95:AB" Called-Station-Id = "tech.test.net.nz" NAS-Port-Id = "eoip-timarutech" MS-CHAP-Domain = "test.net.nz" MS-CHAP-Challenge = 0x8cfad6f1df5918ab44bcca7d4fd0eb9d MS-CHAP2-Response = 0x01007b8394b86094fb4bd086c3e8183f2e1b00000000000000007e68546c2b8eed73be5a12f8cb5175ab4cbedfa2aec45d2b NAS-Identifier = "tech.test.net.nz" Mikrotik-Realm = "test.net.nz" NAS-IP-Address = 10.11.127.229 Proxy-State = 0x3332 # Executing section authorize from file /etc/raddb/sites-enabled/default +group authorize { ++[preprocess] = ok ++[chap] = noop [mschap] Found MS-CHAP attributes. Setting 'Auth-Type = mschap' ++[mschap] = ok ++[digest] = noop [suffix] No '@' in User-Name = "testlane5", looking up realm NULL [suffix] No such realm "NULL" ++[suffix] = noop [eap] No EAP-Message, not doing EAP ++[eap] = noop [sql] expand: %{Stripped-User-Name} -> [sql] ... expanding second conditional [sql] expand: %{User-Name} -> testlane5 [sql] expand: %{%{User-Name}:-DEFAULT} -> testlane5 [sql] expand: %{%{Stripped-User-Name}:-%{%{User-Name}:-DEFAULT}} -> testlane5 [sql] sql_set_user escaped user --> 'testlane5' rlm_sql (sql): Reserving sql socket id: 26 [sql] expand: SELECT id, username, attribute, value, op FROM radcheck WHERE username = '%{SQL-User-Name}' ORDER BY id -> SELECT id, username, attribute, value, op FROM radcheck WHERE username = 'testlane5' ORDER BY id [sql] User found in radcheck table [sql] expand: SELECT id, username, attribute, value, op FROM radreply WHERE username = '%{SQL-User-Name}' ORDER BY id -> SELECT id, username, attribute, value, op FROM radreply WHERE username = 'testlane5' ORDER BY id [sql] expand: SELECT groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority -> SELECT groupname FROM radusergroup WHERE username = 'testlane5' ORDER BY priority [sql] expand: SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = '%{Sql-Group}' ORDER BY id -> SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = 'default' ORDER BY id [sql] User found in group default [sql] expand: SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = '%{Sql-Group}' ORDER BY id -> SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = 'default' ORDER BY id rlm_sql (sql): Released sql socket id: 26 ++[sql] = ok ++[expiration] = noop ++[logintime] = noop [pap] WARNING: Auth-Type already set. Not setting to PAP ++[pap] = noop ++? if (!control:Auth-Type) ? Evaluating !(control:Auth-Type) -> FALSE ++? if (!control:Auth-Type) -> FALSE +} # group authorize = ok Found Auth-Type = MSCHAP # Executing group from file /etc/raddb/sites-enabled/default +group MS-CHAP { [mschap] Creating challenge hash with username: testlane5 [mschap] Client is using MS-CHAPv2 for testlane5, we need NT-Password [mschap] FAILED: MS-CHAP2-Response is incorrect ++[mschap] = reject +} # group MS-CHAP = reject Failed to authenticate the user. Using Post-Auth-Type REJECT # Executing group from file /etc/raddb/sites-enabled/default +group REJECT { [sql] expand: %{Stripped-User-Name} -> [sql] ... expanding second conditional [sql] expand: %{User-Name} -> testlane5 [sql] expand: %{%{User-Name}:-DEFAULT} -> testlane5 [sql] expand: %{%{Stripped-User-Name}:-%{%{User-Name}:-DEFAULT}} -> testlane5 [sql] sql_set_user escaped user --> 'testlane5' [sql] expand: %{User-Password} -> [sql] ... expanding second conditional [sql] expand: %{Chap-Password} -> [sql] expand: INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '%{User-Name}', '%{%{User-Password}:-%{Chap-Password}}', '%{reply:Packet-Type}', '%S') -> INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( 'testlane5', '', 'Access-Reject', '2019-05-19 20:05:12') rlm_sql (sql) in sql_postauth: query is INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( 'testlane5', '', 'Access-Reject', '2019-05-19 20:05:12') rlm_sql (sql): Reserving sql socket id: 25 rlm_sql (sql): Released sql socket id: 25 ++[sql] = ok [attr_filter.access_reject] expand: %{User-Name} -> testlane5 attr_filter: Matched entry DEFAULT at line 11 ++[attr_filter.access_reject] = updated +} # group REJECT = updated Delaying reject of request 3 for 1 seconds Going to the next request Waking up in 0.9 seconds. rad_recv: Access-Request packet from host 10.11.127.229 port 58794, id=32, length=276 Sending duplicate proxied request to home server 127.0.0.1 port 1812 - ID: 116 Sending Access-Request of id 116 to 127.0.0.1 port 1812 Service-Type = Framed-User Framed-Protocol = PPP NAS-Port = 15729458 NAS-Port-Type = Ethernet User-Name = "testlane5" Calling-Station-Id = "02:24:83:47:95:AB" Called-Station-Id = "tech.test.net.nz" NAS-Port-Id = "eoip-timarutech" MS-CHAP-Domain = "test.net.nz" MS-CHAP-Challenge = 0x8cfad6f1df5918ab44bcca7d4fd0eb9d MS-CHAP2-Response = 0x01007b8394b86094fb4bd086c3e8183f2e1b00000000000000007e68546c2b8eed73be5a12f8cb5175ab4cbedfa2aec45d2b NAS-Identifier = "tech.test.net.nz" Mikrotik-Realm = "test.net.nz" NAS-IP-Address = 10.11.127.229 Proxy-State = 0x3332 Waking up in 0.6 seconds. rad_recv: Access-Request packet from host 127.0.0.1 port 1814, id=116, length=267 Waiting to send Access-Reject to client localhost port 1814 - ID: 116 Waking up in 0.6 seconds. rad_recv: Access-Request packet from host 10.11.127.229 port 58794, id=32, length=276 Sending duplicate proxied request to home server 127.0.0.1 port 1812 - ID: 116 Sending Access-Request of id 116 to 127.0.0.1 port 1812 Service-Type = Framed-User Framed-Protocol = PPP NAS-Port = 15729458 NAS-Port-Type = Ethernet User-Name = "testlane5" Calling-Station-Id = "02:24:83:47:95:AB" Called-Station-Id = "tech.test.net.nz" NAS-Port-Id = "eoip-tech" MS-CHAP-Domain = "test.net.nz" MS-CHAP-Challenge = 0x8cfad6f1df5918ab44bcca7d4fd0eb9d MS-CHAP2-Response = 0x01007b8394b86094fb4bd086c3e8183f2e1b00000000000000007e68546c2b8eed73be5a12f8cb5175ab4cbedfa2aec45d2b NAS-Identifier = "tech.test.net.nz" Mikrotik-Realm = "test.net.nz" NAS-IP-Address = 10.11.127.229 Proxy-State = 0x3332 Waking up in 0.3 seconds. rad_recv: Access-Request packet from host 127.0.0.1 port 1814, id=116, length=267 Waiting to send Access-Reject to client localhost port 1814 - ID: 116 Waking up in 0.3 seconds. Sending delayed reject for request 3 Sending Access-Reject of id 116 to 127.0.0.1 port 1814 MS-CHAP-Error = "\001E=691 R=1" Proxy-State = 0x3332 Waking up in 3.8 seconds. rad_recv: Access-Reject packet from host 127.0.0.1 port 1812, id=116, length=42 MS-CHAP-Error = "\001E=691 R=1" Proxy-State = 0x3332 # Executing section post-proxy from file /etc/raddb/sites-enabled/default +group post-proxy { [eap] No pre-existing handler found ++[eap] = noop +} # group post-proxy = noop Using Post-Auth-Type REJECT # Executing group from file /etc/raddb/sites-enabled/default +group REJECT { [sql] expand: %{Stripped-User-Name} -> testlane5 [sql] expand: %{%{Stripped-User-Name}:-%{%{User-Name}:-DEFAULT}} -> testlane5 [sql] sql_set_user escaped user --> 'testlane5' [sql] expand: %{User-Password} -> [sql] ... expanding second conditional [sql] expand: %{Chap-Password} -> [sql] expand: INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '%{User-Name}', '%{%{User-Password}:-%{Chap-Password}}', '%{reply:Packet-Type}', '%S') -> INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( 'testlane5@test.net.nz', '', 'Access-Reject', '2019-05-19 20:05:12') rlm_sql (sql) in sql_postauth: query is INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( 'testlane5@test.net.nz', '', 'Access-Reject', '2019-05-19 20:05:12') rlm_sql (sql): Reserving sql socket id: 24 rlm_sql (sql): Released sql socket id: 24 ++[sql] = ok [attr_filter.access_reject] expand: %{User-Name} -> testlane5@test.net.nz attr_filter: Matched entry DEFAULT at line 11 ++[attr_filter.access_reject] = updated +} # group REJECT = updated Sending Access-Reject of id 32 to 10.11.127.229 port 58794 MS-CHAP-Error = "\001E=691 R=1" Finished request 2. Going to the next request Waking up in 3.8 seconds. ^C [root@radius-220q ~]# Warm Regards, Matthew McTague Head of Infrastructure, Reliance Networks d. +64 3 222 6013 t. 0800 483 882 (+64 3 683 9090) Website | Service Desk | Internet Services Reliance Networks Ltd accepts no liability for the content of this email, or for the consequences of any actions taken on the basis of the information provided, unless that information is subsequently confirmed in writing. Any views or opinions presented in this email are solely those of the author and do not necessarily represent those of the company. -----Original Message----- From: Freeradius-Users <freeradius-users-bounces+matthew.mctague=reliance.net.nz@lists.freeradius.org> On Behalf Of Alan DeKok Sent: Thursday, 2 May 2019 12:51 AM To: FreeRadius users mailing list <freeradius-users@lists.freeradius.org> Subject: Re: MS-CHAPv2 not working On Apr 30, 2019, at 7:36 PM, Matthew McTague via Freeradius-Users <freeradius-users@lists.freeradius.org> wrote:
Does anyone know why MS-CHAPv2 may not be working on a new FreeRADIUS implementation we've built?
You edited the configuration and broke it. Don't do that.
I'm trying to do MS-CHAPv2 with a SQL database, not with LDAP.
The issue only occurs when a realm is added to the username (on the RADIUS client). As I understand, as nostrip is not entered in the relevant realm block in /etc/raddb/proxy.conf, this should be stripped.
The MS-CHAP calculations are done with the User-Name. If you mangle the User-Name, the MS-CHAP calculations will be wrong.
radiusd -X output is at https://pastebin.com/kK9JYsF0
Just post it here. That's what the documentation says to do.
Information and passwords have been changed / sanitized.
• rad_recv: Access-Request packet from host 10.11.127.229 port 60421, id=170, length=278 • Service-Type = Framed-User • Framed-Protocol = PPP • NAS-Port = 15732821 • NAS-Port-Type = Ethernet • User-Name = "testuser@test.net.nz" This is the real User-Name. • [preprocess] expand: %{User-Name} -> testuser@test.net.nz • [preprocess] hints: Matched DEFAULT at 36 • [preprocess] expand: %{1} -> testuser Then you mangle it, for reasons unexplained. • [mschap] Creating challenge hash with username: testuser Which is not the correct User-Name. • [mschap] Client is using MS-CHAPv2 for testuser, we need NT-Password • [mschap] FAILED: MS-CHAP2-Response is incorrect And MS-CHAP fails. Don't re-write the User-Name. If you need to support realms, the "realms" module does this already. And, it does it in a way that *doesn't* break everything. Delete the "hints" configuration which re-writes the User-Name. Add in "test.net.nz" as a local realm to proxy.conf. It *will* work. Alan DeKok. - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
