FreeRadius2+daloRAIUS mschap problem: No Cleartext-Password configured

[Denis Iskandarov]

>  You have deleted the output which is needed to help you.
>
>> Found Auth-Type = MSCHAP
>> +- entering group MS-CHAP {...}
>> [mschap] No Cleartext-Password configured.  Cannot create LM-Password.
>> [mschap] No Cleartext-Password configured.  Cannot create NT-Password.
>
>  So... you haven't told the server what the "known good" password is
> for the user.  Go fix that.

Sorry i didn't understand you. which good known password ?I'm using
daloRADIUS. and while creating user i appended cleartext password :=
to it:
Here is output of radcheck table:

mysql> select * from radcheck;
+----+----------+--------------------+----+---------+
|  id | username | attribute               | op | value   |
+----+----------+--------------------+----+---------+
|  2 | ubnt123  | Cleartext-Password | := | ubnt321 |
+----+----------+--------------------+----+---------+

It's almost same string as in users text conf, but in mysql table form.
Something changed while using sql. freeradius or mschap can't
understand this field. Don't know why.
Here is full debug output:

FreeRADIUS Version 2.1.7, for host i686-redhat-linux-gnu, built on Mar
31 2010 at 00:25:31
Copyright (C) 1999-2009 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 v2.
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/always
including configuration file /etc/raddb/modules/chap
including configuration file /etc/raddb/modules/wimax
including configuration file /etc/raddb/modules/exec
including configuration file /etc/raddb/modules/attr_filter
including configuration file /etc/raddb/modules/pam
including configuration file /etc/raddb/modules/echo
including configuration file /etc/raddb/modules/smbpasswd
including configuration file /etc/raddb/modules/sql_log
including configuration file /etc/raddb/modules/digest
including configuration file /etc/raddb/modules/cui
including configuration file /etc/raddb/modules/detail
including configuration file /etc/raddb/modules/attr_rewrite
including configuration file /etc/raddb/modules/acct_unique
including configuration file /etc/raddb/modules/inner-eap
including configuration file /etc/raddb/modules/expr
including configuration file /etc/raddb/modules/sqlcounter_expire_on_login
including configuration file /etc/raddb/modules/policy
including configuration file /etc/raddb/modules/expiration
including configuration file /etc/raddb/modules/mac2ip
including configuration file /etc/raddb/modules/checkval
including configuration file /etc/raddb/modules/otp
including configuration file /etc/raddb/modules/sradutmp
including configuration file /etc/raddb/modules/realm
including configuration file /etc/raddb/modules/detail.log
including configuration file /etc/raddb/modules/passwd
including configuration file /etc/raddb/modules/linelog
including configuration file /etc/raddb/modules/radutmp
including configuration file /etc/raddb/modules/files
including configuration file /etc/raddb/modules/logintime
including configuration file /etc/raddb/modules/mschap
including configuration file /etc/raddb/modules/pap
including configuration file /etc/raddb/modules/preprocess
including configuration file /etc/raddb/modules/mac2vlan
including configuration file /etc/raddb/modules/ippool
including configuration file /etc/raddb/modules/counter
including configuration file /etc/raddb/modules/perl
including configuration file /etc/raddb/modules/etc_group
including configuration file /etc/raddb/modules/smsotp
including configuration file /etc/raddb/modules/unix
including configuration file /etc/raddb/modules/detail.example.com
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/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
group = radiusd
user = radiusd
including dictionary file /etc/raddb/dictionary
main {
       prefix = "/usr"
       localstatedir = "/var"
       logdir = "/var/log/radius"
       libdir = "/usr/lib/freeradius"
       radacctdir = "/var/log/radius/radacct"
       hostname_lookups = no
       max_request_time = 30
       cleanup_delay = 5
       max_requests = 1024
       allow_core_dumps = no
       pidfile = "/var/run/radiusd/radiusd.pid"
       checkrad = "/usr/sbin/checkrad"
       debug_level = 0
       proxy_requests = yes
 log {
       stripped_names = no
       auth = yes
       auth_badpass = no
       auth_goodpass = no
 }
 security {
       max_attributes = 200
       reject_delay = 1
       status_server = yes
 }
}
radiusd: #### Loading Realms and Home Servers ####
 proxy server {
       retry_delay = 5
       retry_count = 3
       default_fallback = no
       dead_time = 120
       wake_all_if_all_dead = no
 }
 home_server localhost {
       ipaddr = 127.0.0.1
       port = 1812
       type = "auth"
       secret = "testing123"
       response_window = 20
       max_outstanding = 65536
       require_message_authenticator = no
       zombie_period = 40
       status_check = "status-server"
       ping_interval = 30
       check_interval = 30
       num_answers_to_alive = 3
       num_pings_to_alive = 3
       revive_interval = 120
       status_check_timeout = 4
       irt = 2
       mrt = 16
       mrc = 5
       mrd = 30
 }
 home_server_pool my_auth_failover {
       type = fail-over
       home_server = localhost
 }
 realm example.com {
       auth_pool = my_auth_failover
 }
 realm LOCAL {
 }
radiusd: #### Loading Clients ####
 client localhost {
       ipaddr = 127.0.0.1
       require_message_authenticator = no
       secret = "testing123"
       nastype = "other"
 }
radiusd: #### Instantiating modules ####
 instantiate {
 Module: Linked to module rlm_exec
 Module: Instantiating exec
 exec {
       wait = no
       input_pairs = "request"
       shell_escape = yes
 }
 Module: Linked to module rlm_expr
 Module: Instantiating expr
 Module: Linked to module rlm_expiration
 Module: Instantiating expiration
 expiration {
       reply-message = "Password Has Expired  "
 }
 Module: Linked to module rlm_logintime
 Module: Instantiating logintime
 logintime {
       reply-message = "You are calling outside your allowed timespan  "
       minimum-timeout = 60
 }
 }
radiusd: #### Loading Virtual Servers ####
server inner-tunnel {
 modules {
 Module: Checking authenticate {...} for more modules to load
 Module: Linked to module rlm_pap
 Module: Instantiating pap
 pap {
       encryption_scheme = "auto"
       auto_header = no
 }
 Module: Linked to module rlm_chap
 Module: Instantiating chap
 Module: Linked to module rlm_mschap
 Module: Instantiating mschap
 mschap {
       use_mppe = yes
       require_encryption = no
       require_strong = no
       with_ntdomain_hack = no
 }
 Module: Linked to module rlm_unix
 Module: Instantiating unix
 unix {
       radwtmp = "/var/log/radius/radwtmp"
 }
 Module: Linked to module rlm_eap
 Module: Instantiating eap
 eap {
       default_eap_type = "ttls"
       timer_expire = 60
       ignore_unknown_eap_types = no
       cisco_accounting_username_bug = no
       max_sessions = 2048
 }
 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
       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 = "lettheserverin"
       dh_file = "/etc/raddb/certs/dh"
       random_file = "/etc/raddb/certs/random"
       fragment_size = 1024
       include_length = yes
       check_crl = no
       cipher_list = "DEFAULT"
       make_cert_command = "/etc/raddb/certs/bootstrap"
   cache {
       enable = no
       lifetime = 24
       max_entries = 255
   }
  }
 Module: Linked to sub-module rlm_eap_ttls
 Module: Instantiating eap-ttls
  ttls {
       default_eap_type = "mschapv2"
       copy_request_to_tunnel = no
       use_tunneled_reply = yes
       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"
  }
 Module: Linked to sub-module rlm_eap_mschapv2
 Module: Instantiating eap-mschapv2
  mschapv2 {
       with_ntdomain_hack = no
  }
 Module: Checking authorize {...} for more modules to load
 Module: Linked to module rlm_realm
 Module: Instantiating suffix
 realm suffix {
       format = "suffix"
       delimiter = "@"
       ignore_default = no
       ignore_null = no
 }
 Module: Linked to module rlm_files
 Module: Instantiating files
 files {
       usersfile = "/etc/raddb/users"
       acctusersfile = "/etc/raddb/acct_users"
       preproxy_usersfile = "/etc/raddb/preproxy_users"
       compat = "no"
 }
 Module: Checking session {...} for more modules to load
 Module: Linked to module rlm_radutmp
 Module: Instantiating 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: Linked to module rlm_attr_filter
 Module: Instantiating attr_filter.access_reject
 attr_filter attr_filter.access_reject {
       attrsfile = "/etc/raddb/attrs.access_reject"
       key = "%{User-Name}"
 }
 } # modules
} # server
server {
 modules {
 Module: Checking authenticate {...} for more modules to load
 Module: Checking authorize {...} for more modules to load
 Module: Linked to module rlm_preprocess
 Module: Instantiating 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
 }
 Module: Linked to module rlm_sql
 Module: Instantiating sql
 sql {
       driver = "rlm_sql_mysql"
       server = "localhost"
       port = ""
       login = "radius"
       password = "radpass"
       radius_db = "radiusdb"
       read_groups = yes
       sqltrace = no
       sqltracefile = "/var/log/radius/sqltrace.sql"
       readclients = yes
       deletestalesessions = yes
       num_sql_socks = 5
       lifetime = 0
       max_queries = 0
       sql_user_name = "%{User-Name}"
       default_user_profile = ""
       nas_query = "SELECT id, nasname, shortname, type, secret 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}',
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}',              '%{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}',              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}', '%{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:/radiusdb
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): Processing generate_sql_clients
rlm_sql (sql) in generate_sql_clients: query is SELECT id, nasname,
shortname, type, secret FROM nas
rlm_sql (sql): Reserving sql socket id: 4
rlm_sql (sql): Read entry
nasname=192.168.0.140,shortname=ubntAP,secret=secret123
rlm_sql (sql): Adding client 192.168.0.140 (ubntAP, server=<none>) to
clients list
rlm_sql (sql): Released sql socket id: 4
 Module: Checking preacct {...} for more modules to load
 Module: Linked to module rlm_acct_unique
 Module: Instantiating acct_unique
 acct_unique {
       key = "User-Name, Acct-Session-Id, NAS-IP-Address,
Client-IP-Address, NAS-Port"
 }
 Module: Checking accounting {...} for more modules to load
 Module: Linked to module rlm_detail
 Module: Instantiating detail
 detail {
       detailfile = "/var/log/radius/radacct/%{Client-IP-Address}/detail-%Y%m%d"
       header = "%t"
       detailperm = 384
       dirperm = 493
       locking = no
       log_packet_header = no
 }
 Module: Instantiating attr_filter.accounting_response
 attr_filter attr_filter.accounting_response {
       attrsfile = "/etc/raddb/attrs.accounting_response"
       key = "%{User-Name}"
 }
 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"
 }
}
Listening on authentication address * port 1812
Listening on accounting address * port 1813
Listening on command file /var/run/radiusd/radiusd.sock
Listening on proxy address * port 1814
Ready to process requests.
rad_recv: Access-Request packet from host 192.168.0.140 port 2049,
id=1, length=149
       User-Name = "anonymous"
       NAS-Port = 0
       Called-Station-Id = "00-15-6D-5A-50-3B:denis"
       Calling-Station-Id = "00-15-6D-5A-4F-5E"
       Framed-MTU = 1400
       NAS-Port-Type = Wireless-802.11
       Connect-Info = "CONNECT 0Mbps 802.11"
       EAP-Message = 0x02fa000e01616e6f6e796d6f7573
       Message-Authenticator = 0xac94d259aa586e1aa292f1aadfdc7339
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
[suffix] No '@' in User-Name = "anonymous", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 250 length 14
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
++[unix] returns notfound
++[files] returns noop
[sql]   expand: %{User-Name} -> anonymous
[sql] sql_set_user escaped user --> 'anonymous'
rlm_sql (sql): Reserving sql socket id: 3
[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 = 'anonymous'           ORDER
BY id
[sql]   expand: SELECT groupname           FROM radusergroup
WHERE username = '%{SQL-User-Name}'           ORDER BY priority ->
SELECT groupname           FROM radusergroup           WHERE username
= 'anonymous'           ORDER BY priority
rlm_sql (sql): Released sql socket id: 3
[sql] User anonymous not found
++[sql] returns notfound
++[expiration] returns noop
++[logintime] returns noop
[pap] WARNING! No "known good" password found for the user.
Authentication may fail because of this.
++[pap] returns noop
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] EAP Identity
[eap] processing type tls
[tls] Initiate
[tls] Start returned 1
++[eap] returns handled
Sending Access-Challenge of id 1 to 192.168.0.140 port 2049
       EAP-Message = 0x01fb00061520
       Message-Authenticator = 0x00000000000000000000000000000000
       State = 0x0cf285250c099090f5ca032a85c8d937
Finished request 0.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 192.168.0.140 port 2049,
id=2, length=215
       User-Name = "anonymous"
       NAS-Port = 0
       Called-Station-Id = "00-15-6D-5A-50-3B:denis"
       Calling-Station-Id = "00-15-6D-5A-4F-5E"
       Framed-MTU = 1400
       NAS-Port-Type = Wireless-802.11
       Connect-Info = "CONNECT 0Mbps 802.11"
       EAP-Message =
0x02fb003e150016030100330100002f03014c7eb17031983dc1f05cf67c4874672da16661e0a6bb6b5bf02b9363bb09aecd000008002f000a000500040100
       State = 0x0cf285250c099090f5ca032a85c8d937
       Message-Authenticator = 0x28f397a6bd9217ead8012b8e68633262
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
[suffix] No '@' in User-Name = "anonymous", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 251 length 62
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/ttls
[eap] processing type ttls
[ttls] Authenticate
[ttls] processing EAP-TLS
[ttls] eaptls_verify returned 7
[ttls] Done initial handshake
[ttls]     (other): before/accept initialization
[ttls]     TLS_accept: before/accept initialization
[ttls] <<< TLS 1.0 Handshake [length 0033], ClientHello
[ttls]     TLS_accept: SSLv3 read client hello A
[ttls] >>> TLS 1.0 Handshake [length 002a], ServerHello
[ttls]     TLS_accept: SSLv3 write server hello A
[ttls] >>> TLS 1.0 Handshake [length 07ad], Certificate
[ttls]     TLS_accept: SSLv3 write certificate A
[ttls] >>> TLS 1.0 Handshake [length 0004], ServerHelloDone
[ttls]     TLS_accept: SSLv3 write server done A
[ttls]     TLS_accept: SSLv3 flush data
[ttls]     TLS_accept: Need to read more data: SSLv3 read client certificate A
In SSL Handshake Phase
In SSL Accept mode
[ttls] eaptls_process returned 13
++[eap] returns handled
Sending Access-Challenge of id 2 to 192.168.0.140 port 2049
       EAP-Message =
0x01fc040015c0000007ea160301002a0200002603014c89ce5d85d35d2db033d50b1f22bcf5029b44e866dc8218668f4542d871220e00002f0016030107ad0b0007a90007a6000369308203653082024da003020102020101300d06092a864886f70d0101040500306e310b30090603550406130247453110300e060355040813075462696c6973693110300e060355040713075462696c697369310c300a060355040a130343444e3120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d310b3009060355040313024341301e170d3130303930313035303230395a170d3131303930313035303230395a3065310b3009
       EAP-Message =
0x0603550406130247453110300e060355040813075462696c697369310c300a060355040a130343444e311430120603550403140b7365727665725f636572743120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d30820122300d06092a864886f70d01010105000382010f003082010a0282010100cb28b5fad4ee983cefa247bb9644d3f03104dbb70b2ae7ce305cc29b3a0c01613aa8c6658c899242480eafc4033b17592f91249c80eac7f4e76e1b68c23b0f3a8488c78bc31cf4f89a02c04c7b1c4b18e42cebc258562c95c1f7fadabf8829e564320a5d44c36a44821de34eb1f8372e00f71fea0bbd9427714e17
       EAP-Message =
0xa4969a11ca1ecf6dc2c52daedb87bb6c0626eb31373d9bd022cc5b5eebf7c24a7192f4ddb3e3f8a59e9a6f38c3db478c4e193b6ee39253c7516f3ffd884990fe484caf834cab9a3764257740dd8ef0a6c9971cce31680c403c139e6b25af22d5fdbc51e2cb71e027d4efcf8dcfcc2878abf62a85259352eaa2392df023b7e873f9c6d0a0010203010001a317301530130603551d25040c300a06082b06010505070301300d06092a864886f70d0101040500038201010020fdb05a4d9444467227e202ae60ab605a011f2cfafa144745e46461ad8d21ae6649fb503030b17c840d7222e3534087ea273e72fbc91cfc4f120410ee0bbe55ae038e6806c7
       EAP-Message =
0xde57f9942aaa7ef923f1b0c25299fd736f9a76f813446e745f544ee038c0ff91a70c4462299df611d077785e70598e55ea76d0e328998c141bc6cba479a0b57d5ac8b133dca47f568d25694f10204b42c5583a6d8a748fa51f01a8bc6a39550c03ba204521684b334e01be8ed742b71e62ddadabc407527f2af67233f8006ef7230ec9243a49856a187918a1b82a933953e8a5e3f4bdac279d9dfea6ecc0dae33ed9c6b12d248c91c5864b07382ab72d763598d0f15c25da5885000437308204333082031ba003020102020900eb338f458ae2bb82300d06092a864886f70d0101050500306e310b30090603550406130247453110300e060355040813
       EAP-Message = 0x075462696c6973693110300e
       Message-Authenticator = 0x00000000000000000000000000000000
       State = 0x0cf285250d0e9090f5ca032a85c8d937
Finished request 1.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 192.168.0.140 port 2049,
id=3, length=159
       User-Name = "anonymous"
       NAS-Port = 0
       Called-Station-Id = "00-15-6D-5A-50-3B:denis"
       Calling-Station-Id = "00-15-6D-5A-4F-5E"
       Framed-MTU = 1400
       NAS-Port-Type = Wireless-802.11
       Connect-Info = "CONNECT 0Mbps 802.11"
       EAP-Message = 0x02fc00061500
       State = 0x0cf285250d0e9090f5ca032a85c8d937
       Message-Authenticator = 0xa3ef774453c0ceeed3d7cadf55a96a69
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
[suffix] No '@' in User-Name = "anonymous", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 252 length 6
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/ttls
[eap] processing type ttls
[ttls] Authenticate
[ttls] processing EAP-TLS
[ttls] Received TLS ACK
[ttls] ACK handshake fragment handler
[ttls] eaptls_verify returned 1
[ttls] eaptls_process returned 13
++[eap] returns handled
Sending Access-Challenge of id 3 to 192.168.0.140 port 2049
       EAP-Message =
0x01fd03fe1580000007ea060355040713075462696c697369310c300a060355040a130343444e3120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d310b3009060355040313024341301e170d3130303930313034353832375a170d3131303930313034353832375a306e310b30090603550406130247453110300e060355040813075462696c6973693110300e060355040713075462696c697369310c300a060355040a130343444e3120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d310b300906035504031302434130820122300d06092a864886f70d01010105000382010f00
       EAP-Message =
0x3082010a0282010100bb437513ea7906ac7e0038f28a785b96125be2f90014b9968107372de3848a679f67fb04804f4a307b4ca68b00e7956fa031692eff725a45b00afd14246a9e8137a0187368fa075a5c46e843c05ff388e631b3b058efdbc5d108fcd96ed82e9c88b1937a571bb5fb1e060a286fc128cd96bab1e228a2e2c22d565770efe1b1efe212e9c1b3b7ca387f9c036ad3ea366c3b0ea82d7a3d23b14829407bc682d482045d192b60ab9a6394a027b7bc49d38c282325f590bcce675abca9535e1c799bacc5dea5edfaf8053b3b95c7be70e4114c82eaeca04df6d4bb48cf7cb4e78ede01ee7d09b41bca3f7c35242459fd377dde4923bb
       EAP-Message =
0x5ed60dd5f35134bfe2141d870203010001a381d33081d0301d0603551d0e04160414ead0d24ae9bb918615768e7831e0286ab4f3eda93081a00603551d230481983081958014ead0d24ae9bb918615768e7831e0286ab4f3eda9a172a470306e310b30090603550406130247453110300e060355040813075462696c6973693110300e060355040713075462696c697369310c300a060355040a130343444e3120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d310b3009060355040313024341820900eb338f458ae2bb82300c0603551d13040530030101ff300d06092a864886f70d0101050500038201010076d5
       EAP-Message =
0xaac529863a0528c51a16a9e8bd2a9b333db815ab37b8e466e291140ac850c00ef020b2f4c987a13b769e7c7fabef202104d25211811cced3d382a60c63a7bcd68e60aa16a02da9405a47f52874211057883f1e19db85fb191902c28cc3970a09ee34567e38ace18c38fb281b714fb6dedbe9c48f035530d54b05174a5ef5dd7fc1eaf3c9f0a7f50614c951550743a23909e28cfba97f84ced4e806f94394c5f8b7ac0cc9ee44566e1da7d6beb3aa43dc9970dd619e6956b96a52c783803b9a69532d4a420379d09947869233ba034984e50211d84793ef326bf96f2754a40a067e7c934791dde7fc083acfa77f1bbe556d2078f0daef3149c1bbdee983
       EAP-Message = 0xe316030100040e000000
       Message-Authenticator = 0x00000000000000000000000000000000
       State = 0x0cf285250e0f9090f5ca032a85c8d937
Finished request 2.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 192.168.0.140 port 2049,
id=4, length=487
       User-Name = "anonymous"
       NAS-Port = 0
       Called-Station-Id = "00-15-6D-5A-50-3B:denis"
       Calling-Station-Id = "00-15-6D-5A-4F-5E"
       Framed-MTU = 1400
       NAS-Port-Type = Wireless-802.11
       Connect-Info = "CONNECT 0Mbps 802.11"
       EAP-Message =
0x02fd014c15001603010106100001020100729cbf897bf3a064bf90c5fa71d04e459e973206bee721a1c380fbcd9b55895dc136ae2429609ba901b8e008735318f11c5ecfffb8f7a6aa80c6f1648a1857acfb741b6253c1d12108a9bc8b4978f1c8000c6537391d5453312cd51c191ad5891056b3184212dea06ea0fb34d34588196240988fa87eb2022ed4b515c5fb6482471a041f6db3f543d7ba93c7bf9f17ffd06aee90bdbf84ee5384c9cd64e3a205c72101df0388719cdcc1259e5dcaafdbcfc3a366e288c380c2eb1694a1c55ac0456c69a44710000686f0fcf3472a3f856237e5609533e9372e535999f1fd5b81bf2d97ba2d7a3daf01ab6d4b
       EAP-Message =
0xda4133913245d2068dec21a27bcd2922a292f927140301000101160301003042e373239e0843a4cc250d4342abdaf298288de885cb0825dc750e28fd1fbcdf75106d9f6c093d5ce93d492f62825c41
       State = 0x0cf285250e0f9090f5ca032a85c8d937
       Message-Authenticator = 0x0b6c83a177b8adad5b12d5fc90fe405a
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
[suffix] No '@' in User-Name = "anonymous", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 253 length 253
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/ttls
[eap] processing type ttls
[ttls] Authenticate
[ttls] processing EAP-TLS
[ttls] eaptls_verify returned 7
[ttls] Done initial handshake
[ttls] <<< TLS 1.0 Handshake [length 0106], ClientKeyExchange
[ttls]     TLS_accept: SSLv3 read client key exchange A
[ttls] <<< TLS 1.0 ChangeCipherSpec [length 0001]
[ttls] <<< TLS 1.0 Handshake [length 0010], Finished
[ttls]     TLS_accept: SSLv3 read finished A
[ttls] >>> TLS 1.0 ChangeCipherSpec [length 0001]
[ttls]     TLS_accept: SSLv3 write change cipher spec A
[ttls] >>> TLS 1.0 Handshake [length 0010], Finished
[ttls]     TLS_accept: SSLv3 write finished A
[ttls]     TLS_accept: SSLv3 flush data
[ttls]     (other): SSL negotiation finished successfully
SSL Connection Established
[ttls] eaptls_process returned 13
++[eap] returns handled
Sending Access-Challenge of id 4 to 192.168.0.140 port 2049
       EAP-Message =
0x01fe004515800000003b1403010001011603010030e229dc1cb062dfcf15b5c71e1f18002e2d6cce47fbf54724de37fb2ed5329ed1ac412e6ea508d09050bd03da519b7ae0
       Message-Authenticator = 0x00000000000000000000000000000000
       State = 0x0cf285250f0c9090f5ca032a85c8d937
Finished request 3.
Going to the next request
Waking up in 4.8 seconds.
rad_recv: Access-Request packet from host 192.168.0.140 port 2049,
id=5, length=308
       User-Name = "anonymous"
       NAS-Port = 0
       Called-Station-Id = "00-15-6D-5A-50-3B:denis"
       Calling-Station-Id = "00-15-6D-5A-4F-5E"
       Framed-MTU = 1400
       NAS-Port-Type = Wireless-802.11
       Connect-Info = "CONNECT 0Mbps 802.11"
       EAP-Message =
0x02fe009b1500170301009098a967b0a969cc0bbd49ab57cba686cbd09013ca867e242837a92588718deec4e3947e1ea64fd2694bc222d95f4e379c0e62b2fc6079078b4feed51734ea75c7a8a735e3e7134f0799a5d642fc90f72630e94bd2f140a76881ec9e515c632f4d78ef9f0cd2f9e1c56d215c7dd1034d608599551a5394d4f420376505253e9787ae0947bdbff64be2247e3f7774b4f680
       State = 0x0cf285250f0c9090f5ca032a85c8d937
       Message-Authenticator = 0x87a22190cd135e6f6eb1ced42076c5e2
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
[suffix] No '@' in User-Name = "anonymous", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 254 length 155
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/ttls
[eap] processing type ttls
[ttls] Authenticate
[ttls] processing EAP-TLS
[ttls] eaptls_verify returned 7
[ttls] Done initial handshake
[ttls] eaptls_process returned 7
[ttls] Session established.  Proceeding to decode tunneled attributes.
[ttls] Got tunneled request
       User-Name = "ubnt123"
       MS-CHAP-Challenge = 0xab051a6f881fd88d7a8835046659db14
       MS-CHAP2-Response =
0x6d005c024ea0d4b07c90ec0c577a21f1a883000000000000000046b4f8c18e124e6475085b321c43a12df5897af9ae580006
       FreeRADIUS-Proxied-To = 127.0.0.1
[ttls] Sending tunneled request
       User-Name = "ubnt123"
       MS-CHAP-Challenge = 0xab051a6f881fd88d7a8835046659db14
       MS-CHAP2-Response =
0x6d005c024ea0d4b07c90ec0c577a21f1a883000000000000000046b4f8c18e124e6475085b321c43a12df5897af9ae580006
       FreeRADIUS-Proxied-To = 127.0.0.1
server inner-tunnel {
+- entering group authorize {...}
++[chap] returns noop
[mschap] Found MS-CHAP attributes.  Setting 'Auth-Type  = mschap'
++[mschap] returns ok
++[unix] returns notfound
[suffix] No '@' in User-Name = "ubnt123", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
++[control] returns noop
[eap] No EAP-Message, not doing EAP
++[eap] returns noop
++[files] returns noop
++[expiration] returns noop
++[logintime] returns noop
++[pap] returns noop
Found Auth-Type = MSCHAP
+- entering group MS-CHAP {...}
[mschap] No Cleartext-Password configured.  Cannot create LM-Password.
[mschap] No Cleartext-Password configured.  Cannot create NT-Password.
[mschap] Told to do MS-CHAPv2 for ubnt123 with NT-Password
[mschap] FAILED: No NT/LM-Password.  Cannot perform authentication.
[mschap] FAILED: MS-CHAP2-Response is incorrect
++[mschap] returns reject
Failed to authenticate the user.
Login incorrect: [ubnt123] (from client ubntAP port 0 via TLS tunnel)
} # server inner-tunnel
[ttls] Got tunneled reply code 3
       MS-CHAP-Error = "mE=691 R=1"
[ttls] Got tunneled Access-Reject
[eap] Handler failed in EAP/ttls
[eap] Failed in EAP select
++[eap] returns invalid
Failed to authenticate the user.
Login incorrect: [anonymous] (from client ubntAP port 0 cli 00-15-6D-5A-4F-5E)
Using Post-Auth-Type Reject
+- entering group REJECT {...}
[attr_filter.access_reject]     expand: %{User-Name} -> anonymous
 attr_filter: Matched entry DEFAULT at line 11
++[attr_filter.access_reject] returns updated
Delaying reject of request 4 for 1 seconds
Going to the next request
Waking up in 0.9 seconds.
Sending delayed reject for request 4
Sending Access-Reject of id 5 to 192.168.0.140 port 2049
       EAP-Message = 0x04fe0004
       Message-Authenticator = 0x00000000000000000000000000000000
Waking up in 3.8 seconds.
Cleaning up request 0 ID 1 with timestamp +64
Cleaning up request 1 ID 2 with timestamp +64
Cleaning up request 2 ID 3 with timestamp +64
Cleaning up request 3 ID 4 with timestamp +64
Waking up in 1.0 seconds.
Cleaning up request 4 ID 5 with timestamp +64
Ready to process requests.