MS-CHAPv2 not working

Matthew McTague matthew.mctague at reliance.net.nz
Sun May 19 10:28:50 CEST 2019


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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at lists.freeradius.org> On Behalf Of Alan DeKok
Sent: Thursday, 2 May 2019 12:51 AM
To: FreeRadius users mailing list <freeradius-users at lists.freeradius.org>
Subject: Re: MS-CHAPv2 not working

On Apr 30, 2019, at 7:36 PM, Matthew McTague via Freeradius-Users <freeradius-users at 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 at test.net.nz"

  This is the real User-Name.

• [preprocess]    expand: %{User-Name} -> testuser at 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
-------------- next part --------------
A non-text attachment was scrubbed...
Name: image676630.png
Type: image/png
Size: 22286 bytes
Desc: image676630.png
URL: <http://lists.freeradius.org/pipermail/freeradius-users/attachments/20190519/f63643e9/attachment-0003.png>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: image196896.png
Type: image/png
Size: 462 bytes
Desc: image196896.png
URL: <http://lists.freeradius.org/pipermail/freeradius-users/attachments/20190519/f63643e9/attachment-0004.png>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: image464512.png
Type: image/png
Size: 556 bytes
Desc: image464512.png
URL: <http://lists.freeradius.org/pipermail/freeradius-users/attachments/20190519/f63643e9/attachment-0005.png>


More information about the Freeradius-Users mailing list