[again] Error "[mschap] No Cleartext-Password configured. Cannot create LM-Password."

15 Jul 2013

      Hi there,

I've googled a while and found different solutions for the error message:
[mschap] No Cleartext-Password configured.  Cannot create LM-Password.

What I've done is, to establish the following setup: Debian 7.1, Samba3,
OpenLDAP and freeradius 2.1.12 (everything on the same machine). A VPN
gateway forwards the authentication requests to the freeradius-server.

While Samba is working fine, VPN-Users cannot login. The following debug
output appears, when trying to:
radtest -t mschap testuser passwd 127.0.0.1:18120 0 <secret> <passwd>

Not sure, at which point I've to act. Would be great, if you could help

<snip>
Mon Jul 15 11:52:13 2013 : Info: FreeRADIUS Version 2.1.12, for host
x86_64-pc-linux-gnu, built on Dec 16 2012 at 13:28:43
Mon Jul 15 11:52:13 2013 : Info: Copyright (C) 1999-2009 The FreeRADIUS
server project and contributors.
Mon Jul 15 11:52:13 2013 : Info: There is NO warranty; not even for
MERCHANTABILITY or FITNESS FOR A
Mon Jul 15 11:52:13 2013 : Info: PARTICULAR PURPOSE.
Mon Jul 15 11:52:13 2013 : Info: You may redistribute copies of FreeRADIUS
under the terms of the
Mon Jul 15 11:52:13 2013 : Info: GNU General Public License v2.
Mon Jul 15 11:52:13 2013 : Info: Starting - reading configuration files ...
Mon Jul 15 11:52:13 2013 : Debug: including configuration file
/etc/freeradius/radiusd.conf
Mon Jul 15 11:52:13 2013 : Debug: including configuration file
/etc/freeradius/proxy.conf
Mon Jul 15 11:52:13 2013 : Debug: including configuration file
/etc/freeradius/clients.conf
Mon Jul 15 11:52:13 2013 : Debug: including files in directory
/etc/freeradius/modules/
Mon Jul 15 11:52:13 2013 : Debug: including configuration file
/etc/freeradius/modules/pam
Mon Jul 15 11:52:13 2013 : Debug: including configuration file
/etc/freeradius/modules/realm
Mon Jul 15 11:52:13 2013 : Debug: including configuration file
/etc/freeradius/modules/always
Mon Jul 15 11:52:13 2013 : Debug: including configuration file
/etc/freeradius/modules/digest
Mon Jul 15 11:52:13 2013 : Debug: including configuration file
/etc/freeradius/modules/etc_group
Mon Jul 15 11:52:13 2013 : Debug: including configuration file
/etc/freeradius/modules/redis
Mon Jul 15 11:52:13 2013 : Debug: including configuration file
/etc/freeradius/modules/attr_rewrite
Mon Jul 15 11:52:13 2013 : Debug: including configuration file
/etc/freeradius/modules/rediswho
Mon Jul 15 11:52:13 2013 : Debug: including configuration file
/etc/freeradius/modules/opendirectory
Mon Jul 15 11:52:13 2013 : Debug: including configuration file
/etc/freeradius/modules/linelog
Mon Jul 15 11:52:13 2013 : Debug: including configuration file
/etc/freeradius/modules/radutmp
Mon Jul 15 11:52:13 2013 : Debug: including configuration file
/etc/freeradius/modules/replicate
Mon Jul 15 11:52:13 2013 : Debug: including configuration file
/etc/freeradius/modules/echo
Mon Jul 15 11:52:13 2013 : Debug: including configuration file
/etc/freeradius/modules/soh
Mon Jul 15 11:52:13 2013 : Debug: including configuration file
/etc/freeradius/modules/unix
Mon Jul 15 11:52:13 2013 : Debug: including configuration file
/etc/freeradius/modules/logintime
Mon Jul 15 11:52:13 2013 : Debug: including configuration file
/etc/freeradius/modules/files
Mon Jul 15 11:52:13 2013 : Debug: including configuration file
/etc/freeradius/modules/dynamic_clients
Mon Jul 15 11:52:13 2013 : Debug: including configuration file
/etc/freeradius/modules/pap
Mon Jul 15 11:52:13 2013 : Debug: including configuration file
/etc/freeradius/modules/otp
Mon Jul 15 11:52:13 2013 : Debug: including configuration file
/etc/freeradius/modules/krb5
Mon Jul 15 11:52:13 2013 : Debug: including configuration file
/etc/freeradius/modules/counter
Mon Jul 15 11:52:13 2013 : Debug: including configuration file
/etc/freeradius/modules/ippool
Mon Jul 15 11:52:13 2013 : Debug: including configuration file
/etc/freeradius/modules/smbpasswd
Mon Jul 15 11:52:13 2013 : Debug: including configuration file
/etc/freeradius/modules/detail.example.com
Mon Jul 15 11:52:13 2013 : Debug: including configuration file
/etc/freeradius/modules/inner-eap
Mon Jul 15 11:52:13 2013 : Debug: including configuration file
/etc/freeradius/modules/attr_filter
Mon Jul 15 11:52:13 2013 : Debug: including configuration file
/etc/freeradius/modules/sqlcounter_expire_on_login
Mon Jul 15 11:52:13 2013 : Debug: including configuration file
/etc/freeradius/modules/chap
Mon Jul 15 11:52:13 2013 : Debug: including configuration file
/etc/freeradius/modules/expr
Mon Jul 15 11:52:13 2013 : Debug: including configuration file
/etc/freeradius/modules/sql_log
Mon Jul 15 11:52:13 2013 : Debug: including configuration file
/etc/freeradius/modules/exec
Mon Jul 15 11:52:13 2013 : Debug: including configuration file
/etc/freeradius/modules/detail.log
Mon Jul 15 11:52:13 2013 : Debug: including configuration file
/etc/freeradius/modules/mac2ip
Mon Jul 15 11:52:13 2013 : Debug: including configuration file
/etc/freeradius/modules/preprocess
Mon Jul 15 11:52:13 2013 : Debug: including configuration file
/etc/freeradius/modules/policy
Mon Jul 15 11:52:13 2013 : Debug: including configuration file
/etc/freeradius/modules/mac2vlan
Mon Jul 15 11:52:13 2013 : Debug: including configuration file
/etc/freeradius/modules/acct_unique
Mon Jul 15 11:52:13 2013 : Debug: including configuration file
/etc/freeradius/modules/mschap
Mon Jul 15 11:52:13 2013 : Debug: including configuration file
/etc/freeradius/modules/detail
Mon Jul 15 11:52:13 2013 : Debug: including configuration file
/etc/freeradius/modules/ldap
Mon Jul 15 11:52:13 2013 : Debug: including configuration file
/etc/freeradius/modules/passwd
Mon Jul 15 11:52:13 2013 : Debug: including configuration file
/etc/freeradius/modules/checkval
Mon Jul 15 11:52:13 2013 : Debug: including configuration file
/etc/freeradius/modules/cui
Mon Jul 15 11:52:13 2013 : Debug: including configuration file
/etc/freeradius/modules/wimax
Mon Jul 15 11:52:13 2013 : Debug: including configuration file
/etc/freeradius/modules/perl
Mon Jul 15 11:52:13 2013 : Debug: including configuration file
/etc/freeradius/modules/sradutmp
Mon Jul 15 11:52:13 2013 : Debug: including configuration file
/etc/freeradius/modules/smsotp
Mon Jul 15 11:52:13 2013 : Debug: including configuration file
/etc/freeradius/modules/expiration
Mon Jul 15 11:52:13 2013 : Debug: including configuration file
/etc/freeradius/modules/ntlm_auth
Mon Jul 15 11:52:13 2013 : Debug: including configuration file
/etc/freeradius/eap.conf
Mon Jul 15 11:52:13 2013 : Debug: including configuration file
/etc/freeradius/policy.conf
Mon Jul 15 11:52:13 2013 : Debug: including files in directory
/etc/freeradius/sites-enabled/
Mon Jul 15 11:52:13 2013 : Debug: including configuration file
/etc/freeradius/sites-enabled/default
Mon Jul 15 11:52:13 2013 : Debug: including configuration file
/etc/freeradius/sites-enabled/inner-tunnel
Mon Jul 15 11:52:13 2013 : Debug: main {
Mon Jul 15 11:52:13 2013 : Debug:     user = "freerad"
Mon Jul 15 11:52:13 2013 : Debug:     group = "freerad"
Mon Jul 15 11:52:13 2013 : Debug:     allow_core_dumps = no
Mon Jul 15 11:52:13 2013 : Debug: }
Mon Jul 15 11:52:13 2013 : Debug: including dictionary file
/etc/freeradius/dictionary
Mon Jul 15 11:52:13 2013 : Debug: main {
Mon Jul 15 11:52:13 2013 : Debug:     name = "freeradius"
Mon Jul 15 11:52:13 2013 : Debug:     prefix = "/usr"
Mon Jul 15 11:52:13 2013 : Debug:     localstatedir = "/var"
Mon Jul 15 11:52:13 2013 : Debug:     sbindir = "/usr/sbin"
Mon Jul 15 11:52:13 2013 : Debug:     logdir = "/var/log/freeradius"
Mon Jul 15 11:52:13 2013 : Debug:     run_dir = "/var/run/freeradius"
Mon Jul 15 11:52:13 2013 : Debug:     libdir = "/usr/lib/freeradius"
Mon Jul 15 11:52:13 2013 : Debug:     radacctdir =
"/var/log/freeradius/radacct"
Mon Jul 15 11:52:13 2013 : Debug:     hostname_lookups = no
Mon Jul 15 11:52:13 2013 : Debug:     max_request_time = 30
Mon Jul 15 11:52:13 2013 : Debug:     cleanup_delay = 5
Mon Jul 15 11:52:13 2013 : Debug:     max_requests = 1024
Mon Jul 15 11:52:13 2013 : Debug:     pidfile =
"/var/run/freeradius/freeradius.pid"
Mon Jul 15 11:52:13 2013 : Debug:     checkrad = "/usr/sbin/checkrad"
Mon Jul 15 11:52:13 2013 : Debug:     debug_level = 0
Mon Jul 15 11:52:13 2013 : Debug:     proxy_requests = yes
Mon Jul 15 11:52:13 2013 : Debug:  log {
Mon Jul 15 11:52:13 2013 : Debug:     stripped_names = no
Mon Jul 15 11:52:13 2013 : Debug:     auth = no
Mon Jul 15 11:52:13 2013 : Debug:     auth_badpass = no
Mon Jul 15 11:52:13 2013 : Debug:     auth_goodpass = no
Mon Jul 15 11:52:13 2013 : Debug:  }
Mon Jul 15 11:52:13 2013 : Debug:  security {
Mon Jul 15 11:52:13 2013 : Debug:     max_attributes = 200
Mon Jul 15 11:52:13 2013 : Debug:     reject_delay = 1
Mon Jul 15 11:52:13 2013 : Debug:     status_server = yes
Mon Jul 15 11:52:13 2013 : Debug:  }
Mon Jul 15 11:52:13 2013 : Debug: }
Mon Jul 15 11:52:13 2013 : Debug: radiusd: #### Loading Realms and Home
Servers ####
Mon Jul 15 11:52:13 2013 : Debug:  proxy server {
Mon Jul 15 11:52:13 2013 : Debug:     retry_delay = 5
Mon Jul 15 11:52:13 2013 : Debug:     retry_count = 3
Mon Jul 15 11:52:13 2013 : Debug:     default_fallback = no
Mon Jul 15 11:52:13 2013 : Debug:     dead_time = 120
Mon Jul 15 11:52:13 2013 : Debug:     wake_all_if_all_dead = no
Mon Jul 15 11:52:13 2013 : Debug:  }
Mon Jul 15 11:52:13 2013 : Debug:  home_server localhost {
Mon Jul 15 11:52:13 2013 : Debug:     ipaddr = 127.0.0.1
Mon Jul 15 11:52:13 2013 : Debug:     port = 1812
Mon Jul 15 11:52:13 2013 : Debug:     type = "auth"
Mon Jul 15 11:52:13 2013 : Debug:     secret = "testing123"
Mon Jul 15 11:52:13 2013 : Debug:     response_window = 20
Mon Jul 15 11:52:13 2013 : Debug:     max_outstanding = 65536
Mon Jul 15 11:52:13 2013 : Debug:     require_message_authenticator = yes
Mon Jul 15 11:52:13 2013 : Debug:     zombie_period = 40
Mon Jul 15 11:52:13 2013 : Debug:     status_check = "status-server"
Mon Jul 15 11:52:13 2013 : Debug:     ping_interval = 30
Mon Jul 15 11:52:13 2013 : Debug:     check_interval = 30
Mon Jul 15 11:52:13 2013 : Debug:     num_answers_to_alive = 3
Mon Jul 15 11:52:13 2013 : Debug:     num_pings_to_alive = 3
Mon Jul 15 11:52:13 2013 : Debug:     revive_interval = 120
Mon Jul 15 11:52:13 2013 : Debug:     status_check_timeout = 4
Mon Jul 15 11:52:13 2013 : Debug:   coa {
Mon Jul 15 11:52:13 2013 : Debug:     irt = 2
Mon Jul 15 11:52:13 2013 : Debug:     mrt = 16
Mon Jul 15 11:52:13 2013 : Debug:     mrc = 5
Mon Jul 15 11:52:13 2013 : Debug:     mrd = 30
Mon Jul 15 11:52:13 2013 : Debug:   }
Mon Jul 15 11:52:13 2013 : Debug:  }
Mon Jul 15 11:52:13 2013 : Debug:  home_server_pool my_auth_failover {
Mon Jul 15 11:52:13 2013 : Debug:     type = fail-over
Mon Jul 15 11:52:13 2013 : Debug:     home_server = localhost
Mon Jul 15 11:52:13 2013 : Debug:  }
Mon Jul 15 11:52:13 2013 : Debug:  realm example.com {
Mon Jul 15 11:52:13 2013 : Debug:     auth_pool = my_auth_failover
Mon Jul 15 11:52:13 2013 : Debug:  }
Mon Jul 15 11:52:13 2013 : Debug:  realm LOCAL {
Mon Jul 15 11:52:13 2013 : Debug:  }
Mon Jul 15 11:52:13 2013 : Debug: radiusd: #### Loading Clients ####
Mon Jul 15 11:52:13 2013 : Debug:  client localhost {
Mon Jul 15 11:52:13 2013 : Debug:     ipaddr = 127.0.0.1
Mon Jul 15 11:52:13 2013 : Debug:     require_message_authenticator = no
Mon Jul 15 11:52:13 2013 : Debug:     secret = "secret"
Mon Jul 15 11:52:13 2013 : Debug:     nastype = "other"
Mon Jul 15 11:52:13 2013 : Debug:  }
Mon Jul 15 11:52:13 2013 : Debug:  client 192.168.1.0/24 {
Mon Jul 15 11:52:13 2013 : Debug:     require_message_authenticator = no
Mon Jul 15 11:52:13 2013 : Debug:     secret = "secret"
Mon Jul 15 11:52:13 2013 : Debug:     shortname = "private-network-1"
Mon Jul 15 11:52:13 2013 : Debug:  }
Mon Jul 15 11:52:13 2013 : Debug: radiusd: #### Instantiating modules ####
Mon Jul 15 11:52:13 2013 : Debug:  instantiate {
Mon Jul 15 11:52:13 2013 : Debug:     (Loaded rlm_exec, checking if it's
valid)
Mon Jul 15 11:52:13 2013 : Debug:  Module: Linked to module rlm_exec
Mon Jul 15 11:52:13 2013 : Debug:  Module: Instantiating module "exec" from
file /etc/freeradius/modules/exec
Mon Jul 15 11:52:13 2013 : Debug:   exec {
Mon Jul 15 11:52:13 2013 : Debug:     wait = no
Mon Jul 15 11:52:13 2013 : Debug:     input_pairs = "request"
Mon Jul 15 11:52:13 2013 : Debug:     shell_escape = yes
Mon Jul 15 11:52:13 2013 : Debug:   }
Mon Jul 15 11:52:13 2013 : Debug:     (Loaded rlm_expr, checking if it's
valid)
Mon Jul 15 11:52:13 2013 : Debug:  Module: Linked to module rlm_expr
Mon Jul 15 11:52:13 2013 : Debug:  Module: Instantiating module "expr" from
file /etc/freeradius/modules/expr
Mon Jul 15 11:52:13 2013 : Debug:     (Loaded rlm_expiration, checking if
it's valid)
Mon Jul 15 11:52:13 2013 : Debug:  Module: Linked to module rlm_expiration
Mon Jul 15 11:52:13 2013 : Debug:  Module: Instantiating module
"expiration" from file /etc/freeradius/modules/expiration
Mon Jul 15 11:52:13 2013 : Debug:   expiration {
Mon Jul 15 11:52:13 2013 : Debug:     reply-message = "Password Has
Expired  "
Mon Jul 15 11:52:13 2013 : Debug:   }
Mon Jul 15 11:52:13 2013 : Debug:     (Loaded rlm_logintime, checking if
it's valid)
Mon Jul 15 11:52:13 2013 : Debug:  Module: Linked to module rlm_logintime
Mon Jul 15 11:52:13 2013 : Debug:  Module: Instantiating module "logintime"
from file /etc/freeradius/modules/logintime
Mon Jul 15 11:52:13 2013 : Debug:   logintime {
Mon Jul 15 11:52:13 2013 : Debug:     reply-message = "You are calling
outside your allowed timespan  "
Mon Jul 15 11:52:13 2013 : Debug:     minimum-timeout = 60
Mon Jul 15 11:52:13 2013 : Debug:   }
Mon Jul 15 11:52:13 2013 : Debug:  }
Mon Jul 15 11:52:13 2013 : Debug: radiusd: #### Loading Virtual Servers ####
Mon Jul 15 11:52:13 2013 : Debug: server { # from file
/etc/freeradius/radiusd.conf
Mon Jul 15 11:52:13 2013 : Debug:  modules {
Mon Jul 15 11:52:13 2013 : Debug:   Module: Creating Auth-Type = digest
Mon Jul 15 11:52:13 2013 : Debug:   Module: Creating Post-Auth-Type = REJECT
Mon Jul 15 11:52:13 2013 : Debug:  Module: Checking authenticate {...} for
more modules to load
Mon Jul 15 11:52:13 2013 : Debug:     (Loaded rlm_pap, checking if it's
valid)
Mon Jul 15 11:52:13 2013 : Debug:  Module: Linked to module rlm_pap
Mon Jul 15 11:52:13 2013 : Debug:  Module: Instantiating module "pap" from
file /etc/freeradius/modules/pap
Mon Jul 15 11:52:13 2013 : Debug:   pap {
Mon Jul 15 11:52:13 2013 : Debug:     encryption_scheme = "auto"
Mon Jul 15 11:52:13 2013 : Debug:     auto_header = yes
Mon Jul 15 11:52:13 2013 : Debug:   }
Mon Jul 15 11:52:13 2013 : Debug:     (Loaded rlm_chap, checking if it's
valid)
Mon Jul 15 11:52:13 2013 : Debug:  Module: Linked to module rlm_chap
Mon Jul 15 11:52:13 2013 : Debug:  Module: Instantiating module "chap" from
file /etc/freeradius/modules/chap
Mon Jul 15 11:52:13 2013 : Debug:     (Loaded rlm_mschap, checking if it's
valid)
Mon Jul 15 11:52:13 2013 : Debug:  Module: Linked to module rlm_mschap
Mon Jul 15 11:52:13 2013 : Debug:  Module: Instantiating module "mschap"
from file /etc/freeradius/modules/mschap
Mon Jul 15 11:52:13 2013 : Debug:   mschap {
Mon Jul 15 11:52:13 2013 : Debug:     use_mppe = yes
Mon Jul 15 11:52:13 2013 : Debug:     require_encryption = no
Mon Jul 15 11:52:13 2013 : Debug:     require_strong = no
Mon Jul 15 11:52:13 2013 : Debug:     with_ntdomain_hack = no
Mon Jul 15 11:52:13 2013 : Debug:     allow_retry = yes
Mon Jul 15 11:52:13 2013 : Debug:   }
Mon Jul 15 11:52:13 2013 : Debug:     (Loaded rlm_digest, checking if it's
valid)
Mon Jul 15 11:52:13 2013 : Debug:  Module: Linked to module rlm_digest
Mon Jul 15 11:52:13 2013 : Debug:  Module: Instantiating module "digest"
from file /etc/freeradius/modules/digest
Mon Jul 15 11:52:13 2013 : Debug:     (Loaded rlm_unix, checking if it's
valid)
Mon Jul 15 11:52:13 2013 : Debug:  Module: Linked to module rlm_unix
Mon Jul 15 11:52:13 2013 : Debug:  Module: Instantiating module "unix" from
file /etc/freeradius/modules/unix
Mon Jul 15 11:52:13 2013 : Debug:   unix {
Mon Jul 15 11:52:13 2013 : Debug:     radwtmp =
"/var/log/freeradius/radwtmp"
Mon Jul 15 11:52:13 2013 : Debug:   }
Mon Jul 15 11:52:13 2013 : Debug:     (Loaded rlm_eap, checking if it's
valid)
Mon Jul 15 11:52:13 2013 : Debug:  Module: Linked to module rlm_eap
Mon Jul 15 11:52:13 2013 : Debug:  Module: Instantiating module "eap" from
file /etc/freeradius/eap.conf
Mon Jul 15 11:52:13 2013 : Debug:   eap {
Mon Jul 15 11:52:13 2013 : Debug:     default_eap_type = "peap"
Mon Jul 15 11:52:13 2013 : Debug:     timer_expire = 60
Mon Jul 15 11:52:13 2013 : Debug:     ignore_unknown_eap_types = no
Mon Jul 15 11:52:13 2013 : Debug:     cisco_accounting_username_bug = no
Mon Jul 15 11:52:13 2013 : Debug:     max_sessions = 4096
Mon Jul 15 11:52:13 2013 : Debug:   }
Mon Jul 15 11:52:13 2013 : Debug:  Module: Linked to sub-module rlm_eap_md5
Mon Jul 15 11:52:13 2013 : Debug:  Module: Instantiating eap-md5
Mon Jul 15 11:52:13 2013 : Debug:  Module: Linked to sub-module rlm_eap_leap
Mon Jul 15 11:52:13 2013 : Debug:  Module: Instantiating eap-leap
Mon Jul 15 11:52:13 2013 : Debug:  Module: Linked to sub-module rlm_eap_gtc
Mon Jul 15 11:52:13 2013 : Debug:  Module: Instantiating eap-gtc
Mon Jul 15 11:52:13 2013 : Debug:    gtc {
Mon Jul 15 11:52:13 2013 : Debug:     challenge = "Password: "
Mon Jul 15 11:52:13 2013 : Debug:     auth_type = "PAP"
Mon Jul 15 11:52:13 2013 : Debug:    }
Mon Jul 15 11:52:13 2013 : Debug:  Module: Linked to sub-module rlm_eap_tls
Mon Jul 15 11:52:13 2013 : Debug:  Module: Instantiating eap-tls
Mon Jul 15 11:52:13 2013 : Debug:    tls {
Mon Jul 15 11:52:13 2013 : Debug:     rsa_key_exchange = no
Mon Jul 15 11:52:13 2013 : Debug:     dh_key_exchange = yes
Mon Jul 15 11:52:13 2013 : Debug:     rsa_key_length = 512
Mon Jul 15 11:52:13 2013 : Debug:     dh_key_length = 512
Mon Jul 15 11:52:13 2013 : Debug:     verify_depth = 0
Mon Jul 15 11:52:13 2013 : Debug:     CA_path = "/etc/freeradius/certs"
Mon Jul 15 11:52:13 2013 : Debug:     pem_file_type = yes
Mon Jul 15 11:52:13 2013 : Debug:     private_key_file =
"/etc/freeradius/certs/server.pem"
Mon Jul 15 11:52:13 2013 : Debug:     certificate_file =
"/etc/freeradius/certs/server.pem"
Mon Jul 15 11:52:13 2013 : Debug:     CA_file =
"/etc/freeradius/certs/ca.pem"
Mon Jul 15 11:52:13 2013 : Debug:     private_key_password = "whatever"
Mon Jul 15 11:52:13 2013 : Debug:     dh_file = "/etc/freeradius/certs/dh"
Mon Jul 15 11:52:13 2013 : Debug:     random_file =
"/etc/freeradius/certs/random"
Mon Jul 15 11:52:13 2013 : Debug:     fragment_size = 1024
Mon Jul 15 11:52:13 2013 : Debug:     include_length = yes
Mon Jul 15 11:52:13 2013 : Debug:     check_crl = no
Mon Jul 15 11:52:13 2013 : Debug:     cipher_list = "DEFAULT"
Mon Jul 15 11:52:13 2013 : Debug:     ecdh_curve = "prime256v1"
Mon Jul 15 11:52:13 2013 : Debug:     cache {
Mon Jul 15 11:52:13 2013 : Debug:     enable = no
Mon Jul 15 11:52:13 2013 : Debug:     lifetime = 24
Mon Jul 15 11:52:13 2013 : Debug:     max_entries = 255
Mon Jul 15 11:52:13 2013 : Debug:     }
Mon Jul 15 11:52:13 2013 : Debug:     verify {
Mon Jul 15 11:52:13 2013 : Debug:     }
Mon Jul 15 11:52:13 2013 : Debug:     ocsp {
Mon Jul 15 11:52:13 2013 : Debug:     enable = no
Mon Jul 15 11:52:13 2013 : Debug:     override_cert_url = yes
Mon Jul 15 11:52:13 2013 : Debug:     url = "http://127.0.0.1/ocsp/"
Mon Jul 15 11:52:13 2013 : Debug:     }
Mon Jul 15 11:52:13 2013 : Debug:    }
Mon Jul 15 11:52:13 2013 : Debug:  Module: Linked to sub-module rlm_eap_ttls
Mon Jul 15 11:52:13 2013 : Debug:  Module: Instantiating eap-ttls
Mon Jul 15 11:52:13 2013 : Debug:    ttls {
Mon Jul 15 11:52:13 2013 : Debug:     default_eap_type = "md5"
Mon Jul 15 11:52:13 2013 : Debug:     copy_request_to_tunnel = no
Mon Jul 15 11:52:13 2013 : Debug:     use_tunneled_reply = no
Mon Jul 15 11:52:13 2013 : Debug:     virtual_server = "inner-tunnel"
Mon Jul 15 11:52:13 2013 : Debug:     include_length = yes
Mon Jul 15 11:52:13 2013 : Debug:    }
Mon Jul 15 11:52:13 2013 : Debug:  Module: Linked to sub-module rlm_eap_peap
Mon Jul 15 11:52:13 2013 : Debug:  Module: Instantiating eap-peap
Mon Jul 15 11:52:13 2013 : Debug:    peap {
Mon Jul 15 11:52:13 2013 : Debug:     default_eap_type = "mschapv2"
Mon Jul 15 11:52:13 2013 : Debug:     copy_request_to_tunnel = no
Mon Jul 15 11:52:13 2013 : Debug:     use_tunneled_reply = no
Mon Jul 15 11:52:13 2013 : Debug:     proxy_tunneled_request_as_eap = yes
Mon Jul 15 11:52:13 2013 : Debug:     virtual_server = "inner-tunnel"
Mon Jul 15 11:52:13 2013 : Debug:     soh = no
Mon Jul 15 11:52:13 2013 : Debug:    }
Mon Jul 15 11:52:13 2013 : Debug:  Module: Linked to sub-module
rlm_eap_mschapv2
Mon Jul 15 11:52:13 2013 : Debug:  Module: Instantiating eap-mschapv2
Mon Jul 15 11:52:13 2013 : Debug:    mschapv2 {
Mon Jul 15 11:52:13 2013 : Debug:     with_ntdomain_hack = no
Mon Jul 15 11:52:13 2013 : Debug:     send_error = no
Mon Jul 15 11:52:13 2013 : Debug:    }
Mon Jul 15 11:52:13 2013 : Debug:  Module: Checking authorize {...} for
more modules to load
Mon Jul 15 11:52:13 2013 : Debug:     (Loaded rlm_preprocess, checking if
it's valid)
Mon Jul 15 11:52:13 2013 : Debug:  Module: Linked to module rlm_preprocess
Mon Jul 15 11:52:13 2013 : Debug:  Module: Instantiating module
"preprocess" from file /etc/freeradius/modules/preprocess
Mon Jul 15 11:52:13 2013 : Debug:   preprocess {
Mon Jul 15 11:52:13 2013 : Debug:     huntgroups =
"/etc/freeradius/huntgroups"
Mon Jul 15 11:52:13 2013 : Debug:     hints = "/etc/freeradius/hints"
Mon Jul 15 11:52:13 2013 : Debug:     with_ascend_hack = no
Mon Jul 15 11:52:13 2013 : Debug:     ascend_channels_per_line = 23
Mon Jul 15 11:52:13 2013 : Debug:     with_ntdomain_hack = no
Mon Jul 15 11:52:13 2013 : Debug:     with_specialix_jetstream_hack = no
Mon Jul 15 11:52:13 2013 : Debug:     with_cisco_vsa_hack = no
Mon Jul 15 11:52:13 2013 : Debug:     with_alvarion_vsa_hack = no
Mon Jul 15 11:52:13 2013 : Debug:   }
Mon Jul 15 11:52:13 2013 : Debug:     (Loaded rlm_realm, checking if it's
valid)
Mon Jul 15 11:52:13 2013 : Debug:  Module: Linked to module rlm_realm
Mon Jul 15 11:52:13 2013 : Debug:  Module: Instantiating module "suffix"
from file /etc/freeradius/modules/realm
Mon Jul 15 11:52:13 2013 : Debug:   realm suffix {
Mon Jul 15 11:52:13 2013 : Debug:     format = "suffix"
Mon Jul 15 11:52:13 2013 : Debug:     delimiter = "@"
Mon Jul 15 11:52:13 2013 : Debug:     ignore_default = no
Mon Jul 15 11:52:13 2013 : Debug:     ignore_null = no
Mon Jul 15 11:52:13 2013 : Debug:   }
Mon Jul 15 11:52:13 2013 : Debug:     (Loaded rlm_files, checking if it's
valid)
Mon Jul 15 11:52:13 2013 : Debug:  Module: Linked to module rlm_files
Mon Jul 15 11:52:13 2013 : Debug:  Module: Instantiating module "files"
from file /etc/freeradius/modules/files
Mon Jul 15 11:52:13 2013 : Debug:   files {
Mon Jul 15 11:52:13 2013 : Debug:     usersfile = "/etc/freeradius/users"
Mon Jul 15 11:52:13 2013 : Debug:     acctusersfile =
"/etc/freeradius/acct_users"
Mon Jul 15 11:52:13 2013 : Debug:     preproxy_usersfile =
"/etc/freeradius/preproxy_users"
Mon Jul 15 11:52:13 2013 : Debug:     compat = "no"
Mon Jul 15 11:52:13 2013 : Debug:   }
Mon Jul 15 11:52:13 2013 : Debug:  Module: Checking preacct {...} for more
modules to load
Mon Jul 15 11:52:13 2013 : Debug:     (Loaded rlm_acct_unique, checking if
it's valid)
Mon Jul 15 11:52:13 2013 : Debug:  Module: Linked to module rlm_acct_unique
Mon Jul 15 11:52:13 2013 : Debug:  Module: Instantiating module
"acct_unique" from file /etc/freeradius/modules/acct_unique
Mon Jul 15 11:52:13 2013 : Debug:   acct_unique {
Mon Jul 15 11:52:13 2013 : Debug:     key = "User-Name, Acct-Session-Id,
NAS-IP-Address, Client-IP-Address, NAS-Port"
Mon Jul 15 11:52:13 2013 : Debug:   }
Mon Jul 15 11:52:13 2013 : Debug:  Module: Checking accounting {...} for
more modules to load
Mon Jul 15 11:52:13 2013 : Debug:     (Loaded rlm_detail, checking if it's
valid)
Mon Jul 15 11:52:13 2013 : Debug:  Module: Linked to module rlm_detail
Mon Jul 15 11:52:13 2013 : Debug:  Module: Instantiating module "detail"
from file /etc/freeradius/modules/detail
Mon Jul 15 11:52:13 2013 : Debug:   detail {
Mon Jul 15 11:52:13 2013 : Debug:     detailfile =
"/var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d"
Mon Jul 15 11:52:13 2013 : Debug:     header = "%t"
Mon Jul 15 11:52:13 2013 : Debug:     detailperm = 384
Mon Jul 15 11:52:13 2013 : Debug:     dirperm = 493
Mon Jul 15 11:52:13 2013 : Debug:     locking = no
Mon Jul 15 11:52:13 2013 : Debug:     log_packet_header = no
Mon Jul 15 11:52:13 2013 : Debug:   }
Mon Jul 15 11:52:13 2013 : Debug:     (Loaded rlm_radutmp, checking if it's
valid)
Mon Jul 15 11:52:13 2013 : Debug:  Module: Linked to module rlm_radutmp
Mon Jul 15 11:52:13 2013 : Debug:  Module: Instantiating module "radutmp"
from file /etc/freeradius/modules/radutmp
Mon Jul 15 11:52:13 2013 : Debug:   radutmp {
Mon Jul 15 11:52:13 2013 : Debug:     filename =
"/var/log/freeradius/radutmp"
Mon Jul 15 11:52:13 2013 : Debug:     username = "%{User-Name}"
Mon Jul 15 11:52:13 2013 : Debug:     case_sensitive = yes
Mon Jul 15 11:52:13 2013 : Debug:     check_with_nas = yes
Mon Jul 15 11:52:13 2013 : Debug:     perm = 384
Mon Jul 15 11:52:13 2013 : Debug:     callerid = yes
Mon Jul 15 11:52:13 2013 : Debug:   }
Mon Jul 15 11:52:13 2013 : Debug:     (Loaded rlm_attr_filter, checking if
it's valid)
Mon Jul 15 11:52:13 2013 : Debug:  Module: Linked to module rlm_attr_filter
Mon Jul 15 11:52:13 2013 : Debug:  Module: Instantiating module
"attr_filter.accounting_response" from file
/etc/freeradius/modules/attr_filter
Mon Jul 15 11:52:13 2013 : Debug:   attr_filter
attr_filter.accounting_response {
Mon Jul 15 11:52:13 2013 : Debug:     attrsfile =
"/etc/freeradius/attrs.accounting_response"
Mon Jul 15 11:52:13 2013 : Debug:     key = "%{User-Name}"
Mon Jul 15 11:52:13 2013 : Debug:     relaxed = no
Mon Jul 15 11:52:13 2013 : Debug:   }
Mon Jul 15 11:52:13 2013 : Debug:  Module: Checking session {...} for more
modules to load
Mon Jul 15 11:52:13 2013 : Debug:  Module: Checking post-proxy {...} for
more modules to load
Mon Jul 15 11:52:13 2013 : Debug:  Module: Checking post-auth {...} for
more modules to load
Mon Jul 15 11:52:13 2013 : Debug:  Module: Instantiating module
"attr_filter.access_reject" from file /etc/freeradius/modules/attr_filter
Mon Jul 15 11:52:13 2013 : Debug:   attr_filter attr_filter.access_reject {
Mon Jul 15 11:52:13 2013 : Debug:     attrsfile =
"/etc/freeradius/attrs.access_reject"
Mon Jul 15 11:52:13 2013 : Debug:     key = "%{User-Name}"
Mon Jul 15 11:52:13 2013 : Debug:     relaxed = no
Mon Jul 15 11:52:13 2013 : Debug:   }
Mon Jul 15 11:52:13 2013 : Debug:  } # modules
Mon Jul 15 11:52:13 2013 : Debug: } # server
Mon Jul 15 11:52:13 2013 : Debug: server inner-tunnel { # from file
/etc/freeradius/sites-enabled/inner-tunnel
Mon Jul 15 11:52:13 2013 : Debug:  modules {
Mon Jul 15 11:52:13 2013 : Debug:  Module: Checking authenticate {...} for
more modules to load
Mon Jul 15 11:52:13 2013 : Debug:  Module: Checking authorize {...} for
more modules to load
Mon Jul 15 11:52:13 2013 : Debug:     (Loaded rlm_ldap, checking if it's
valid)
Mon Jul 15 11:52:13 2013 : Debug:  Module: Linked to module rlm_ldap
Mon Jul 15 11:52:13 2013 : Debug:  Module: Instantiating module "ldap" from
file /etc/freeradius/modules/ldap
Mon Jul 15 11:52:13 2013 : Debug:   ldap {
Mon Jul 15 11:52:13 2013 : Debug:     server = "ldap.test.example.com"
Mon Jul 15 11:52:13 2013 : Debug:     port = 389
Mon Jul 15 11:52:13 2013 : Debug:     password = "secret"
Mon Jul 15 11:52:13 2013 : Debug:     identity =
"cn=admin,dc=example,dc=com"
Mon Jul 15 11:52:13 2013 : Debug:     net_timeout = 1
Mon Jul 15 11:52:13 2013 : Debug:     timeout = 4
Mon Jul 15 11:52:13 2013 : Debug:     timelimit = 3
Mon Jul 15 11:52:13 2013 : Debug:     tls_mode = no
Mon Jul 15 11:52:13 2013 : Debug:     start_tls = no
Mon Jul 15 11:52:13 2013 : Debug:     tls_require_cert = "allow"
Mon Jul 15 11:52:13 2013 : Debug:    tls {
Mon Jul 15 11:52:13 2013 : Debug:     start_tls = no
Mon Jul 15 11:52:13 2013 : Debug:     require_cert = "allow"
Mon Jul 15 11:52:13 2013 : Debug:    }
Mon Jul 15 11:52:13 2013 : Debug:     basedn = "dc=example,dc=com"
Mon Jul 15 11:52:13 2013 : Debug:     filter =
"(uid=%{%{Stripped-User-Name}:-%{User-Name}})"
Mon Jul 15 11:52:13 2013 : Debug:     base_filter =
"(objectclass=radiusprofile)"
Mon Jul 15 11:52:13 2013 : Debug:     password_attribute = "userPassword"
Mon Jul 15 11:52:13 2013 : Debug:     auto_header = no
Mon Jul 15 11:52:13 2013 : Debug:     access_attr_used_for_allow = yes
Mon Jul 15 11:52:13 2013 : Debug:     groupname_attribute = "cn"
Mon Jul 15 11:52:13 2013 : Debug:     groupmembership_filter =
"(|(&(objectClass=GroupOfNames)(member=%{Ldap-UserDn}))(&(objectClass=GroupOfUniqueNames)(uniquemember=%{Ldap-UserDn})))"
Mon Jul 15 11:52:13 2013 : Debug:     dictionary_mapping =
"/etc/freeradius/ldap.attrmap"
Mon Jul 15 11:52:13 2013 : Debug:     ldap_debug = 0
Mon Jul 15 11:52:13 2013 : Debug:     ldap_connections_number = 5
Mon Jul 15 11:52:13 2013 : Debug:     compare_check_items = no
Mon Jul 15 11:52:13 2013 : Debug:     do_xlat = yes
Mon Jul 15 11:52:13 2013 : Debug:     edir_account_policy_check = no
Mon Jul 15 11:52:13 2013 : Debug:     set_auth_type = yes
Mon Jul 15 11:52:13 2013 : Debug:    keepalive {
Mon Jul 15 11:52:13 2013 : Debug:     idle = 60
Mon Jul 15 11:52:13 2013 : Debug:     probes = 3
Mon Jul 15 11:52:13 2013 : Debug:     interval = 3
Mon Jul 15 11:52:13 2013 : Debug:    }
Mon Jul 15 11:52:13 2013 : Debug:   }
Mon Jul 15 11:52:13 2013 : Debug: rlm_ldap: Registering ldap_groupcmp for
Ldap-Group
Mon Jul 15 11:52:13 2013 : Debug: rlm_ldap: Registering ldap_xlat with
xlat_name ldap
Mon Jul 15 11:52:13 2013 : Debug: rlm_ldap: Over-riding set_auth_type, as
there is no module ldap listed in the "authenticate" section.
Mon Jul 15 11:52:13 2013 : Debug: rlm_ldap: reading ldap<->radius mappings
from file /etc/freeradius/ldap.attrmap
Mon Jul 15 11:52:13 2013 : Debug: rlm_ldap: LDAP radiusCheckItem mapped to
RADIUS $GENERIC$
Mon Jul 15 11:52:13 2013 : Debug: rlm_ldap: LDAP radiusReplyItem mapped to
RADIUS $GENERIC$
Mon Jul 15 11:52:13 2013 : Debug: rlm_ldap: LDAP radiusAuthType mapped to
RADIUS Auth-Type
Mon Jul 15 11:52:13 2013 : Debug: rlm_ldap: LDAP radiusSimultaneousUse
mapped to RADIUS Simultaneous-Use
Mon Jul 15 11:52:13 2013 : Debug: rlm_ldap: LDAP radiusCalledStationId
mapped to RADIUS Called-Station-Id
Mon Jul 15 11:52:13 2013 : Debug: rlm_ldap: LDAP radiusCallingStationId
mapped to RADIUS Calling-Station-Id
Mon Jul 15 11:52:13 2013 : Debug: rlm_ldap: LDAP lmPassword mapped to
RADIUS LM-Password
Mon Jul 15 11:52:13 2013 : Debug: rlm_ldap: LDAP ntPassword mapped to
RADIUS NT-Password
Mon Jul 15 11:52:13 2013 : Debug: rlm_ldap: LDAP sambaLmPassword mapped to
RADIUS LM-Password
Mon Jul 15 11:52:13 2013 : Debug: rlm_ldap: LDAP sambaNtPassword mapped to
RADIUS NT-Password
Mon Jul 15 11:52:13 2013 : Debug: rlm_ldap: LDAP dBCSPwd mapped to RADIUS
LM-Password
Mon Jul 15 11:52:13 2013 : Debug: rlm_ldap: LDAP userPassword mapped to
RADIUS Password-With-Header
Mon Jul 15 11:52:13 2013 : Debug: rlm_ldap: LDAP acctFlags mapped to RADIUS
SMB-Account-CTRL-TEXT
Mon Jul 15 11:52:13 2013 : Debug: rlm_ldap: LDAP radiusExpiration mapped to
RADIUS Expiration
Mon Jul 15 11:52:13 2013 : Debug: rlm_ldap: LDAP radiusNASIpAddress mapped
to RADIUS NAS-IP-Address
Mon Jul 15 11:52:13 2013 : Debug: rlm_ldap: LDAP radiusServiceType mapped
to RADIUS Service-Type
Mon Jul 15 11:52:13 2013 : Debug: rlm_ldap: LDAP radiusFramedProtocol
mapped to RADIUS Framed-Protocol
Mon Jul 15 11:52:13 2013 : Debug: rlm_ldap: LDAP radiusFramedIPAddress
mapped to RADIUS Framed-IP-Address
Mon Jul 15 11:52:13 2013 : Debug: rlm_ldap: LDAP radiusFramedIPNetmask
mapped to RADIUS Framed-IP-Netmask
Mon Jul 15 11:52:13 2013 : Debug: rlm_ldap: LDAP radiusFramedRoute mapped
to RADIUS Framed-Route
Mon Jul 15 11:52:13 2013 : Debug: rlm_ldap: LDAP radiusFramedRouting mapped
to RADIUS Framed-Routing
Mon Jul 15 11:52:13 2013 : Debug: rlm_ldap: LDAP radiusFilterId mapped to
RADIUS Filter-Id
Mon Jul 15 11:52:13 2013 : Debug: rlm_ldap: LDAP radiusFramedMTU mapped to
RADIUS Framed-MTU
Mon Jul 15 11:52:13 2013 : Debug: rlm_ldap: LDAP radiusFramedCompression
mapped to RADIUS Framed-Compression
Mon Jul 15 11:52:13 2013 : Debug: rlm_ldap: LDAP radiusLoginIPHost mapped
to RADIUS Login-IP-Host
Mon Jul 15 11:52:13 2013 : Debug: rlm_ldap: LDAP radiusLoginService mapped
to RADIUS Login-Service
Mon Jul 15 11:52:13 2013 : Debug: rlm_ldap: LDAP radiusLoginTCPPort mapped
to RADIUS Login-TCP-Port
Mon Jul 15 11:52:13 2013 : Debug: rlm_ldap: LDAP radiusCallbackNumber
mapped to RADIUS Callback-Number
Mon Jul 15 11:52:13 2013 : Debug: rlm_ldap: LDAP radiusCallbackId mapped to
RADIUS Callback-Id
Mon Jul 15 11:52:13 2013 : Debug: rlm_ldap: LDAP radiusFramedIPXNetwork
mapped to RADIUS Framed-IPX-Network
Mon Jul 15 11:52:13 2013 : Debug: rlm_ldap: LDAP radiusClass mapped to
RADIUS Class
Mon Jul 15 11:52:13 2013 : Debug: rlm_ldap: LDAP radiusSessionTimeout
mapped to RADIUS Session-Timeout
Mon Jul 15 11:52:13 2013 : Debug: rlm_ldap: LDAP radiusIdleTimeout mapped
to RADIUS Idle-Timeout
Mon Jul 15 11:52:13 2013 : Debug: rlm_ldap: LDAP radiusTerminationAction
mapped to RADIUS Termination-Action
Mon Jul 15 11:52:13 2013 : Debug: rlm_ldap: LDAP radiusLoginLATService
mapped to RADIUS Login-LAT-Service
Mon Jul 15 11:52:13 2013 : Debug: rlm_ldap: LDAP radiusLoginLATNode mapped
to RADIUS Login-LAT-Node
Mon Jul 15 11:52:13 2013 : Debug: rlm_ldap: LDAP radiusLoginLATGroup mapped
to RADIUS Login-LAT-Group
Mon Jul 15 11:52:13 2013 : Debug: rlm_ldap: LDAP radiusFramedAppleTalkLink
mapped to RADIUS Framed-AppleTalk-Link
Mon Jul 15 11:52:13 2013 : Debug: rlm_ldap: LDAP
radiusFramedAppleTalkNetwork mapped to RADIUS Framed-AppleTalk-Network
Mon Jul 15 11:52:13 2013 : Debug: rlm_ldap: LDAP radiusFramedAppleTalkZone
mapped to RADIUS Framed-AppleTalk-Zone
Mon Jul 15 11:52:13 2013 : Debug: rlm_ldap: LDAP radiusPortLimit mapped to
RADIUS Port-Limit
Mon Jul 15 11:52:13 2013 : Debug: rlm_ldap: LDAP radiusLoginLATPort mapped
to RADIUS Login-LAT-Port
Mon Jul 15 11:52:13 2013 : Debug: rlm_ldap: LDAP radiusReplyMessage mapped
to RADIUS Reply-Message
Mon Jul 15 11:52:13 2013 : Debug: rlm_ldap: LDAP radiusTunnelType mapped to
RADIUS Tunnel-Type
Mon Jul 15 11:52:13 2013 : Debug: rlm_ldap: LDAP radiusTunnelMediumType
mapped to RADIUS Tunnel-Medium-Type
Mon Jul 15 11:52:13 2013 : Debug: rlm_ldap: LDAP radiusTunnelPrivateGroupId
mapped to RADIUS Tunnel-Private-Group-Id
Mon Jul 15 11:52:13 2013 : Debug: conns: 0x222e460
Mon Jul 15 11:52:13 2013 : Debug:  Module: Checking session {...} for more
modules to load
Mon Jul 15 11:52:13 2013 : Debug:  Module: Checking post-proxy {...} for
more modules to load
Mon Jul 15 11:52:13 2013 : Debug:  Module: Checking post-auth {...} for
more modules to load
Mon Jul 15 11:52:13 2013 : Debug:  } # modules
Mon Jul 15 11:52:13 2013 : Debug: } # server
Mon Jul 15 11:52:13 2013 : Debug: radiusd: #### Opening IP addresses and
Ports ####
Mon Jul 15 11:52:13 2013 : Debug: listen {
Mon Jul 15 11:52:13 2013 : Debug:     type = "auth"
Mon Jul 15 11:52:13 2013 : Debug:     ipaddr = *
Mon Jul 15 11:52:13 2013 : Debug:     port = 0
Mon Jul 15 11:52:13 2013 : Debug: }
Mon Jul 15 11:52:13 2013 : Debug: listen {
Mon Jul 15 11:52:13 2013 : Debug:     type = "acct"
Mon Jul 15 11:52:13 2013 : Debug:     ipaddr = *
Mon Jul 15 11:52:13 2013 : Debug:     port = 0
Mon Jul 15 11:52:13 2013 : Debug: }
Mon Jul 15 11:52:13 2013 : Debug: listen {
Mon Jul 15 11:52:13 2013 : Debug:     type = "auth"
Mon Jul 15 11:52:13 2013 : Debug:     ipaddr = 127.0.0.1
Mon Jul 15 11:52:13 2013 : Debug:     port = 18120
Mon Jul 15 11:52:13 2013 : Debug: }
Mon Jul 15 11:52:13 2013 : Info:  ... adding new socket proxy address *
port 44220
Mon Jul 15 11:52:13 2013 : Debug: Listening on authentication address *
port 1812
Mon Jul 15 11:52:13 2013 : Debug: Listening on accounting address * port
1813
Mon Jul 15 11:52:13 2013 : Debug: Listening on authentication address
127.0.0.1 port 18120 as server inner-tunnel
Mon Jul 15 11:52:13 2013 : Debug: Listening on proxy address * port 1814
Mon Jul 15 11:52:13 2013 : Info: Ready to process requests.
rad_recv: Access-Request packet from host 127.0.0.1 port 51007, id=10,
length=142
    User-Name = "testuser"
    NAS-IP-Address = 127.0.1.1
    NAS-Port = 0
    Message-Authenticator = 0x501b45980cbac2bf712e39b9d39dcbc4
    Framed-Protocol = PPP
    MS-CHAP-Challenge = 0x6f2e8054de0d1c67
    MS-CHAP-Response =
0x0001000000000000000000000000000000000000000000000000d4852e3f509ae7fb76b929072f32e2cfe2d5b2cc1ef4ffaf
Mon Jul 15 11:52:27 2013 : Info: server inner-tunnel {
Mon Jul 15 11:52:27 2013 : Info: # Executing section authorize from file
/etc/freeradius/sites-enabled/inner-tunnel
Mon Jul 15 11:52:27 2013 : Info: +- entering group authorize {...}
Mon Jul 15 11:52:27 2013 : Info: ++[chap] returns noop
Mon Jul 15 11:52:27 2013 : Info: [mschap] Found MS-CHAP attributes.
Setting 'Auth-Type  = mschap'
Mon Jul 15 11:52:27 2013 : Info: ++[mschap] returns ok
Mon Jul 15 11:52:27 2013 : Info: [suffix] No '@' in User-Name = "testuser",
looking up realm NULL
Mon Jul 15 11:52:27 2013 : Info: [suffix] No such realm "NULL"
Mon Jul 15 11:52:27 2013 : Info: ++[suffix] returns noop
Mon Jul 15 11:52:27 2013 : Info: ++[control] returns noop
Mon Jul 15 11:52:27 2013 : Info: [eap] No EAP-Message, not doing EAP
Mon Jul 15 11:52:27 2013 : Info: ++[eap] returns noop
Mon Jul 15 11:52:27 2013 : Info: [files] users: Matched entry DEFAULT at
line 174
Mon Jul 15 11:52:27 2013 : Info: ++[files] returns ok
Mon Jul 15 11:52:27 2013 : Info: [ldap] performing user authorization for
testuser
Mon Jul 15 11:52:27 2013 : Info: [ldap]     expand: %{Stripped-User-Name}
->
Mon Jul 15 11:52:27 2013 : Info: [ldap]     ... expanding second conditional
Mon Jul 15 11:52:27 2013 : Info: [ldap]     expand: %{User-Name} -> testuser
Mon Jul 15 11:52:27 2013 : Info: [ldap]     expand:
(uid=%{%{Stripped-User-Name}:-%{User-Name}}) -> (uid=testuser)
Mon Jul 15 11:52:27 2013 : Info: [ldap]     expand: dc=example,dc=com ->
dc=example,dc=com
Mon Jul 15 11:52:27 2013 : Debug:   [ldap] ldap_get_conn: Checking Id: 0
Mon Jul 15 11:52:27 2013 : Debug:   [ldap] ldap_get_conn: Got Id: 0
Mon Jul 15 11:52:27 2013 : Debug:   [ldap] attempting LDAP reconnection
Mon Jul 15 11:52:27 2013 : Debug:   [ldap] (re)connect to
ldap.test.example.com:389, authentication 0
Mon Jul 15 11:52:27 2013 : Debug:   [ldap] bind as
cn=admin,dc=example,dc=com/010203 to ldap.test.example.com:389
Mon Jul 15 11:52:27 2013 : Debug:   [ldap] waiting for bind result ...
Mon Jul 15 11:52:27 2013 : Debug:   [ldap] Bind was successful
Mon Jul 15 11:52:27 2013 : Debug:   [ldap] performing search in
dc=example,dc=com, with filter (uid=testuser)
Mon Jul 15 11:52:27 2013 : Info: [ldap] Added User-Password =
{SSHA}xxxxxxxxxxxxxxxxxxxxxxxxxx in check items
Mon Jul 15 11:52:27 2013 : Info: [ldap] No default NMAS login sequence
Mon Jul 15 11:52:27 2013 : Info: [ldap] looking for check items in
directory...
Mon Jul 15 11:52:27 2013 : Debug:   [ldap] userPassword ->
Password-With-Header == "{SSHA}xxxxxxxxxxxxxxxx"
Mon Jul 15 11:52:27 2013 : Debug:   [ldap] sambaNtPassword -> NT-Password
== 0xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
Mon Jul 15 11:52:27 2013 : Info: [ldap] looking for reply items in
directory...
Mon Jul 15 11:52:27 2013 : Info: [ldap] user testuser authorized to use
remote access
Mon Jul 15 11:52:27 2013 : Debug:   [ldap] ldap_release_conn: Release Id: 0
Mon Jul 15 11:52:27 2013 : Info: ++[ldap] returns ok
Mon Jul 15 11:52:27 2013 : Info: ++[expiration] returns noop
Mon Jul 15 11:52:27 2013 : Info: ++[logintime] returns noop
Mon Jul 15 11:52:27 2013 : Info: [pap] Normalizing NT-Password from hex
encoding
Mon Jul 15 11:52:27 2013 : Info: [pap] Normalizing SSHA1-Password from
base64 encoding
Mon Jul 15 11:52:27 2013 : Info: [pap] Normalizing SSHA1-Password from
base64 encoding
Mon Jul 15 11:52:27 2013 : Info: [pap] WARNING: Auth-Type already set.  Not
setting to PAP
Mon Jul 15 11:52:27 2013 : Info: ++[pap] returns noop
Mon Jul 15 11:52:27 2013 : Info: Found Auth-Type = MSCHAP
Mon Jul 15 11:52:27 2013 : Info: # Executing group from file
/etc/freeradius/sites-enabled/inner-tunnel
Mon Jul 15 11:52:27 2013 : Info: +- entering group MS-CHAP {...}
Mon Jul 15 11:52:27 2013 : Info: [mschap] No Cleartext-Password
configured.  Cannot create LM-Password.
Mon Jul 15 11:52:27 2013 : Info: [mschap] Found NT-Password
Mon Jul 15 11:52:27 2013 : Info: [mschap] Told to do MS-CHAPv1 with
NT-Password
Mon Jul 15 11:52:27 2013 : Info: [mschap] MS-CHAP-Response is incorrect.
Mon Jul 15 11:52:27 2013 : Info: ++[mschap] returns reject
Mon Jul 15 11:52:27 2013 : Info: Failed to authenticate the user.
Mon Jul 15 11:52:27 2013 : Info: } # server inner-tunnel
Mon Jul 15 11:52:27 2013 : Info: Using Post-Auth-Type Reject
Mon Jul 15 11:52:27 2013 : Info: # Executing group from file
/etc/freeradius/sites-enabled/inner-tunnel
Mon Jul 15 11:52:27 2013 : Info: +- entering group REJECT {...}
Mon Jul 15 11:52:27 2013 : Info: [attr_filter.access_reject]     expand:
%{User-Name} -> testuser
Mon Jul 15 11:52:27 2013 : Debug: attr_filter: Matched entry DEFAULT at
line 11
Mon Jul 15 11:52:27 2013 : Info: ++[attr_filter.access_reject] returns
updated
Mon Jul 15 11:52:27 2013 : Info: Delaying reject of request 0 for 1 seconds
Mon Jul 15 11:52:27 2013 : Debug: Going to the next request
Mon Jul 15 11:52:27 2013 : Debug: Waking up in 0.9 seconds.
Mon Jul 15 11:52:28 2013 : Info: Sending delayed reject for request 0
Sending Access-Reject of id 10 to 127.0.0.1 port 51007
    MS-CHAP-Error = "\000E=691 R=1"
Mon Jul 15 11:52:28 2013 : Debug: Waking up in 4.9 seconds.
</snip>

[again] Error "[mschap] No Cleartext-Password configured. Cannot create LM-Password."

Holger Wesser