Authentication Problem with PEAP and openldap

9 Jan 2009

      Hello,

native wired xp 802.1X client with PEAP (mschapv2) tries to authenticate via
freeradius against openldap with an md4 encoded utf-16e password hash. The
authentication fails. If we use the hash instead of the clear-text password
with the xp client, the authentication works fine. There must be some
problems with the encryption of the password. How do we fix the problem? Any
help is appreciated.

Here are the radiusd.conf file and the debug output aof radiusd -X:

Best Regards, Michael

<radiusd.conf>
prefix = /usr
exec_prefix = /usr
sysconfdir = /etc
localstatedir = /var
sbindir = /usr/sbin
logdir = ${localstatedir}/log/radius
raddbdir = ${sysconfdir}/raddb
radacctdir = ${logdir}/radacct

confdir = ${raddbdir}
run_dir = ${localstatedir}/run/radiusd

log_file = ${logdir}/radius.log

libdir = /usr/lib

pidfile = ${run_dir}/radiusd.pid

user = radiusd
group = radiusd

max_request_time = 30

delete_blocked_requests = no

cleanup_delay = 5

max_requests = 1024

bind_address = *

port = 0

hostname_lookups = no

allow_core_dumps = no

regular_expressions        = yes
extended_expressions        = yes

log_stripped_names = yes

log_auth = yes

log_auth_badpass = no
log_auth_goodpass = no

usercollide = no

lower_user = no
lower_pass = no

nospace_user = no
nospace_pass = no

checkrad = ${sbindir}/checkrad

security {
        max_attributes = 200

        reject_delay = 1

        status_server = no
}

proxy_requests  = yes
$INCLUDE  ${confdir}/proxy.conf

$INCLUDE  ${confdir}/clients.conf

snmp        = no
$INCLUDE  ${confdir}/snmp.conf

thread pool {
        start_servers = 5

        max_servers = 32

        min_spare_servers = 3
        max_spare_servers = 10

        max_requests_per_server = 0
}

modules {

        pap {
                encryption_scheme = crypt
        }

        chap {
                authtype = CHAP

        }

        pam {
                pam_auth = radiusd
        }

        unix {
                cache = no

                cache_reload = 600

                radwtmp = ${logdir}/radwtmp
        }

$INCLUDE ${confdir}/eap.conf

        mschap {

                authtype = MS-CHAP

                use_mppe = yes

                require_encryption = yes

        }

        ldap {
                server = "ldaps://XXXXXXXXXX.XX"
                identity = "uid=XXX,o=XXX,dc=XXX,dc=de"
                password = XXXXXXX
                basedn = "ou=XXX,ou=XXX,o=XXX,dc=XXX,dc=de"
                filter = "(uid=%{Stripped-User-Name:-%{User-Name}})"

                start_tls = no

                tls_cacertfile        = /etc/openldap/cacerts/ca-bundle.crt

                dictionary_mapping = ${raddbdir}/ldap.attrmap

                ldap_connections_number = 5

                password_attribute = userPassword

                timeout = 4
                timelimit = 3
                net_timeout = 1

        }

        realm IPASS {
                format = prefix
                delimiter = "/"
                ignore_default = no
                ignore_null = no
        }

        realm suffix {
                format = suffix
                delimiter = "@"
                ignore_default = no
                ignore_null = no
        }

        realm realmpercent {
                format = suffix
                delimiter = "%"
                ignore_default = no
                ignore_null = no
        }

        realm ntdomain {
                format = prefix
                delimiter = "\\"
                ignore_default = no
                ignore_null = no
        }

        checkval {
                item-name = Calling-Station-Id

                check-name = Calling-Station-Id

                data-type = string

        }

        preprocess {
                huntgroups = ${confdir}/huntgroups
                hints = ${confdir}/hints

                with_ascend_hack = no
                ascend_channels_per_line = 23

                with_ntdomain_hack = no

                with_specialix_jetstream_hack = no

                with_cisco_vsa_hack = no
        }

        files {
                usersfile = ${confdir}/users
                acctusersfile = ${confdir}/acct_users

                compat = no
        }

        detail {
                detailfile = ${radacctdir}/sammeldir/detail

                detailperm = 0600
        }

        acct_unique {
                key = "User-Name, Acct-Session-Id, NAS-IP-Address,
Client-IP-Address, NAS-Port"
        }

        $INCLUDE  ${confdir}/sql.conf

        radutmp {
                filename = ${logdir}/radutmp

                username = %{User-Name}

                case_sensitive = yes

                check_with_nas = yes

                perm = 0600

                callerid = "yes"
        }

        radutmp sradutmp {
                filename = ${logdir}/sradutmp
                perm = 0644
                callerid = "no"
        }

        attr_filter {
                attrsfile = ${confdir}/attrs
        }

        counter daily {
                filename = ${raddbdir}/db.daily
                key = User-Name
                count-attribute = Acct-Session-Time
                reset = daily
                counter-name = Daily-Session-Time
                check-name = Max-Daily-Session
                allowed-servicetype = Framed-User
                cache-size = 5000
        }

        always fail {
                rcode = fail
        }
        always reject {
                rcode = reject
        }
        always ok {
                rcode = ok
                simulcount = 0
                mpp = no
        }

        expr {
        }

        digest {
        }

        exec {
                wait = yes
                input_pairs = request
        }

        exec echo {
                wait = yes

                program = "/bin/echo %{User-Name}"

                input_pairs = request

                output_pairs = reply

        }

        ippool main_pool {

                range-start = 192.168.1.1
                range-stop = 192.168.3.254

                netmask = 255.255.255.0

                cache-size = 800

                session-db = ${raddbdir}/db.ippool

                ip-index = ${raddbdir}/db.ipindex

                override = no

                maximum-timeout = 0
        }

}

instantiate {
        exec

        expr
}

authorize {
        preprocess

        chap

        mschap

        suffix

        eap

        files

        ldap
}

authenticate {
        Auth-Type PAP {
                pap
        }

        Auth-Type CHAP {
                chap
        }

        Auth-Type MS-CHAP {
                mschap
        }

        unix

        Auth-Type LDAP {
                ldap
        }

        eap

}

preacct {
        preprocess

        acct_unique

        suffix

        files
}

accounting {
        detail

        unix

        radutmp
 }

session {
        radutmp
 }

 post-auth {

 }

pre-proxy {

}

post-proxy {
         eap
}
</radiusd.conf>

<radiusd -X>
rad_recv: Access-Request packet from host 141.2.252.203:62849, id=206,
length=86
        User-Name = "plisch01"
        EAP-Message = 0x0200000d01706c697363683031
        Message-Authenticator = 0xf0812bbe8b0e990ff9c6206d353405de
        NAS-Identifier = "cb-jur-vc0-11og"
        NAS-Port-Type = Virtual
  Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 0
  modcall[authorize]: module "preprocess" returns ok for request 0
  modcall[authorize]: module "chap" returns noop for request 0
  modcall[authorize]: module "mschap" returns noop for request 0
    rlm_realm: No '@' in User-Name = "plisch01", looking up realm NULL
    rlm_realm: No such realm "NULL"
  modcall[authorize]: module "suffix" returns noop for request 0
  rlm_eap: EAP packet type response id 0 length 13
  rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
  modcall[authorize]: module "eap" returns updated for request 0
  modcall[authorize]: module "files" returns notfound for request 0
rlm_ldap: - authorize
rlm_ldap: performing user authorization for plisch01
radius_xlat:  '(uid=plisch01)'
radius_xlat:  'ou=XXX,ou=XXX,o=XXX,dc=XXX,dc=de'
rlm_ldap: ldap_get_conn: Checking Id: 0
rlm_ldap: ldap_get_conn: Got Id: 0
rlm_ldap: attempting LDAP reconnection
rlm_ldap: (re)connect to ldaps://XXX.XE, authentication 0
rlm_ldap: setting TLS CACert File to /etc/openldap/cacerts/ca-bundle.crt
rlm_ldap: bind as uid=XXX,o=XXX,dc=XXX,dc=de/XXXX to ldaps://XXX
rlm_ldap: waiting for bind result ...
rlm_ldap: Bind was successful
rlm_ldap: performing search in ou=XXX,ou=XXX,o=XXX,dc=XXX,dc=de, with filter
(uid=plisch01)
rlm_ldap: Added password 4183.... in check items
rlm_ldap: looking for check items in directory...
rlm_ldap: looking for reply items in directory...
rlm_ldap: user plisch01 authorized to use remote access
rlm_ldap: ldap_release_conn: Release Id: 0
  modcall[authorize]: module "ldap" returns ok for request 0
modcall: group authorize returns updated for request 0
  rad_check_password:  Found Auth-Type EAP
auth: type "EAP"
  Processing the authenticate section of radiusd.conf
modcall: entering group authenticate for request 0
  rlm_eap: EAP Identity
  rlm_eap: processing type md5
rlm_eap_md5: Issuing Challenge
  modcall[authenticate]: module "eap" returns handled for request 0
modcall: group authenticate returns handled for request 0
Sending Access-Challenge of id 206 to 141.2.252.203:62849
        EAP-Message = 0x010100160410c412f76e7e655747b06f3e294c7fed9a
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0xbda20678cb572e52f1a93c3ce8de3099
Finished request 0
Going to the next request
--- Walking the entire request list ---
Waking up in 6 seconds...
rad_recv: Access-Request packet from host 141.2.252.203:62849, id=229,
length=97
        User-Name = "plisch01"
        State = 0xbda20678cb572e52f1a93c3ce8de3099
        EAP-Message = 0x020100060319
        Message-Authenticator = 0xa2b38e829929b3245f489b88fef80135
        NAS-Identifier = "cb-jur-vc0-11og"
        NAS-Port-Type = Virtual
  Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 1
  modcall[authorize]: module "preprocess" returns ok for request 1
  modcall[authorize]: module "chap" returns noop for request 1
  modcall[authorize]: module "mschap" returns noop for request 1
    rlm_realm: No '@' in User-Name = "plisch01", looking up realm NULL
    rlm_realm: No such realm "NULL"
  modcall[authorize]: module "suffix" returns noop for request 1
  rlm_eap: EAP packet type response id 1 length 6
  rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
  modcall[authorize]: module "eap" returns updated for request 1
  modcall[authorize]: module "files" returns notfound for request 1
rlm_ldap: - authorize
rlm_ldap: performing user authorization for plisch01
radius_xlat:  '(uid=plisch01)'
radius_xlat:  'ou=XXX,ou=XXX,o=XXX,dc=XXX,dc=de'
rlm_ldap: ldap_get_conn: Checking Id: 0
rlm_ldap: ldap_get_conn: Got Id: 0
rlm_ldap: performing search in ou=XXX,ou=XXX,o=XXX,dc=XXX,dc=de, with filter
(uid=plisch01)
rlm_ldap: Added password 4183..... in check items
rlm_ldap: looking for check items in directory...
rlm_ldap: looking for reply items in directory...
rlm_ldap: user plisch01 authorized to use remote access
rlm_ldap: ldap_release_conn: Release Id: 0
  modcall[authorize]: module "ldap" returns ok for request 1
modcall: group authorize returns updated for request 1
  rad_check_password:  Found Auth-Type EAP
auth: type "EAP"
  Processing the authenticate section of radiusd.conf
modcall: entering group authenticate for request 1
  rlm_eap: Request found, released from the list
  rlm_eap: EAP NAK
 rlm_eap: EAP-NAK asked for EAP-Type/peap
  rlm_eap: processing type tls
  rlm_eap_tls: Initiate
  rlm_eap_tls: Start returned 1
  modcall[authenticate]: module "eap" returns handled for request 1
modcall: group authenticate returns handled for request 1
Sending Access-Challenge of id 229 to 141.2.252.203:62849
        EAP-Message = 0x010200061920
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x48a99a491f1506a34ab971b65e1e9eed
Finished request 1
Going to the next request
Waking up in 6 seconds...
rad_recv: Access-Request packet from host 141.2.252.203:62849, id=131,
length=171
        User-Name = "plisch01"
        State = 0x48a99a491f1506a34ab971b65e1e9eed
        EAP-Message =
0x0202005019800000004616030100410100003d0301496755f6f21ae795ee2b9dbe7e24064c
e03e31795d9a4a18607059f3614c6afe00001600040005000a00090064006200030006001300
1200630100
        Message-Authenticator = 0x99aced399bcbe6e1af0c51ee3c8f01d1
        NAS-Identifier = "cb-jur-vc0-11og"
        NAS-Port-Type = Virtual
  Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 2
  modcall[authorize]: module "preprocess" returns ok for request 2
  modcall[authorize]: module "chap" returns noop for request 2
  modcall[authorize]: module "mschap" returns noop for request 2
    rlm_realm: No '@' in User-Name = "plisch01", looking up realm NULL
    rlm_realm: No such realm "NULL"
  modcall[authorize]: module "suffix" returns noop for request 2
  rlm_eap: EAP packet type response id 2 length 80
  rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
  modcall[authorize]: module "eap" returns updated for request 2
  modcall[authorize]: module "files" returns notfound for request 2
rlm_ldap: - authorize
rlm_ldap: performing user authorization for plisch01
radius_xlat:  '(uid=plisch01)'
radius_xlat:  'ou=XXX,ou=XXX,o=XXX,dc=XXX,dc=de'
rlm_ldap: ldap_get_conn: Checking Id: 0
rlm_ldap: ldap_get_conn: Got Id: 0
rlm_ldap: performing search in ou=XXX,ou=XXX,o=XXX,dc=XXX,dc=de, with filter
(uid=plisch01)
rlm_ldap: Added password 4183... in check items
rlm_ldap: looking for check items in directory...
rlm_ldap: looking for reply items in directory...
rlm_ldap: user plisch01 authorized to use remote access
rlm_ldap: ldap_release_conn: Release Id: 0
  modcall[authorize]: module "ldap" returns ok for request 2
modcall: group authorize returns updated for request 2
  rad_check_password:  Found Auth-Type EAP
auth: type "EAP"
  Processing the authenticate section of radiusd.conf
modcall: entering group authenticate for request 2
  rlm_eap: Request found, released from the list
  rlm_eap: EAP/peap
  rlm_eap: processing type peap
  rlm_eap_peap: Authenticate
  rlm_eap_tls: processing TLS
rlm_eap_tls:  Length Included
  eaptls_verify returned 11 
    (other): before/accept initialization 
    TLS_accept: before/accept initialization 
  rlm_eap_tls: <<< TLS 1.0 Handshake [length 0041], ClientHello  
    TLS_accept: SSLv3 read client hello A 
  rlm_eap_tls: >>> TLS 1.0 Handshake [length 004a], ServerHello  
    TLS_accept: SSLv3 write server hello A 
  rlm_eap_tls: >>> TLS 1.0 Handshake [length 0694], Certificate  
    TLS_accept: SSLv3 write certificate A 
  rlm_eap_tls: >>> TLS 1.0 Handshake [length 0004], ServerHelloDone  
    TLS_accept: SSLv3 write server done A 
    TLS_accept: SSLv3 flush data 
    TLS_accept:error in SSLv3 read client certificate A 
In SSL Handshake Phase 
In SSL Accept mode  
  eaptls_process returned 13 
  rlm_eap_peap: EAPTLS_HANDLED
  modcall[authenticate]: module "eap" returns handled for request 2
modcall: group authenticate returns handled for request 2
Sending Access-Challenge of id 131 to 141.2.252.203:62849
        EAP-Message =
0x0103040a19c0000006f1160301004a020000460301496755f3badec494486cf4bae34461c0
6b0505d69a956ae2d5a803f146feb962202cb7719a8ffcc825336c500975192cfb8a5e653a69
77d938ccde5707711b5eaa00040016030106940b00069000068d0002cd308202c930820232a0
03020102020102300d06092a864886f70d010104050030819f310b3009060355040613024341
3111300f0603550408130850726f76696e63653112301006035504071309536f6d6520436974
7931153013060355040a130c4f7267616e697a6174696f6e31123010060355040b13096c6f63
616c686f7374311b301906035504031312436c69656e74206365
        EAP-Message =
0x7274696669636174653121301f06092a864886f70d0109011612636c69656e74406578616d
706c652e636f6d301e170d3034303132353133323631305a170d303530313234313332363130
5a30819b310b30090603550406130243413111300f0603550408130850726f76696e63653112
301006035504071309536f6d65204369747931153013060355040a130c4f7267616e697a6174
696f6e31123010060355040b13096c6f63616c686f73743119301706035504031310526f6f74
206365727469666963617465311f301d06092a864886f70d0109011610726f6f74406578616d
706c652e636f6d30819f300d06092a864886f70d010101050003
        EAP-Message =
0x818d0030818902818100dac525422bfedb082629a2cba44b3449c90d0ab462fb72c8434a78
2098863d7eb7d7e70028c2b7ad555a51cc756cf4fa1d7091615ab450d5289553ae6616aff014
a55085d6b8fb4aee98638e426175cdd36c665c63cda177d34920eb30585edc8773999c2980f8
1ad4638bbbea1c82d054023db7ef24a3ec1c3f6241a903d7f30203010001a317301530130603
551d25040c300a06082b06010505070301300d06092a864886f70d0101040500038181007a2d
921b1cf13bf2982a9178ec9ede6d88edc178a2e8bd40a0a06fb6f0769957884cd70845370834
96fd184165293f583c8e8240eb68e042c94b15752e4c07e80d09
        EAP-Message =
0x779afa3dd55c24fa54ac292d77205d1c2477ed30d59f57caf9bd21ff2a8d16cc0911c50e4f
295763fcb60efa3c3d2d0e43850f6e6fbe284902f6e83503650003ba308203b63082031fa003
020102020100300d06092a864886f70d010104050030819f310b300906035504061302434131
11300f0603550408130850726f76696e63653112301006035504071309536f6d652043697479
31153013060355040a130c4f7267616e697a6174696f6e31123010060355040b13096c6f6361
6c686f7374311b301906035504031312436c69656e742063657274696669636174653121301f
06092a864886f70d0109011612636c69656e74406578616d706c
        EAP-Message = 0x652e636f6d301e170d3034303132353133323630375a
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x4d941206f16d48604e5278275172f5d9
Finished request 2
Going to the next request
Waking up in 6 seconds...
rad_recv: Access-Request packet from host 141.2.252.203:62849, id=12,
length=97
        User-Name = "plisch01"
        State = 0x4d941206f16d48604e5278275172f5d9
        EAP-Message = 0x020300061900
        Message-Authenticator = 0x36256183de48f93989f06e14bc11f188
        NAS-Identifier = "cb-jur-vc0-11og"
        NAS-Port-Type = Virtual
  Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 3
  modcall[authorize]: module "preprocess" returns ok for request 3
  modcall[authorize]: module "chap" returns noop for request 3
  modcall[authorize]: module "mschap" returns noop for request 3
    rlm_realm: No '@' in User-Name = "plisch01", looking up realm NULL
    rlm_realm: No such realm "NULL"
  modcall[authorize]: module "suffix" returns noop for request 3
  rlm_eap: EAP packet type response id 3 length 6
  rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
  modcall[authorize]: module "eap" returns updated for request 3
  modcall[authorize]: module "files" returns notfound for request 3
rlm_ldap: - authorize
rlm_ldap: performing user authorization for plisch01
radius_xlat:  '(uid=plisch01)'
radius_xlat:  'ou=XXX,ou=XXX,o=XXX,dc=XXX,dc=de'
rlm_ldap: ldap_get_conn: Checking Id: 0
rlm_ldap: ldap_get_conn: Got Id: 0
rlm_ldap: performing search in ou=XXX,ou=XXX,o=XXX,dc=XXX,dc=de, with filter
(uid=plisch01)
rlm_ldap: Added password 4183.... in check items
rlm_ldap: looking for check items in directory...
rlm_ldap: looking for reply items in directory...
rlm_ldap: user plisch01 authorized to use remote access
rlm_ldap: ldap_release_conn: Release Id: 0
  modcall[authorize]: module "ldap" returns ok for request 3
modcall: group authorize returns updated for request 3
  rad_check_password:  Found Auth-Type EAP
auth: type "EAP"
  Processing the authenticate section of radiusd.conf
modcall: entering group authenticate for request 3
  rlm_eap: Request found, released from the list
  rlm_eap: EAP/peap
  rlm_eap: processing type peap
  rlm_eap_peap: Authenticate
  rlm_eap_tls: processing TLS
rlm_eap_tls: Received EAP-TLS ACK message
  rlm_eap_tls: ack handshake fragment handler
  eaptls_verify returned 1 
  eaptls_process returned 13 
  rlm_eap_peap: EAPTLS_HANDLED
  modcall[authenticate]: module "eap" returns handled for request 3
modcall: group authenticate returns handled for request 3
Sending Access-Challenge of id 12 to 141.2.252.203:62849
        EAP-Message =
0x010402f71900170d3036303132343133323630375a30819f310b3009060355040613024341
3111300f0603550408130850726f76696e63653112301006035504071309536f6d6520436974
7931153013060355040a130c4f7267616e697a6174696f6e31123010060355040b13096c6f63
616c686f7374311b301906035504031312436c69656e74206365727469666963617465312130
1f06092a864886f70d0109011612636c69656e74406578616d706c652e636f6d30819f300d06
092a864886f70d010101050003818d0030818902818100d4c5b19724f164acf1ffb189db1c8f
bff4f14396ea7cb1e90f78d69451725377895dfe52ccb99b41e8
        EAP-Message =
0x0ddeb58b127a943f4f58cbc562878192fbdc6fece9f871e7c130d35cf5188817e9b133249e
dd2a1c75d31043ae87553cec7a77ef26aa7d74281db9b77e17c6446c5dd9b188b43250ca0229
963722a123a726b00b4027fd0203010001a381ff3081fc301d0603551d0e0416041468d36d3e
1ee7bc9d5a057021c363da1365d1ade33081cc0603551d230481c43081c1801468d36d3e1ee7
bc9d5a057021c363da1365d1ade3a181a5a481a230819f310b30090603550406130243413111
300f0603550408130850726f76696e63653112301006035504071309536f6d65204369747931
153013060355040a130c4f7267616e697a6174696f6e31123010
        EAP-Message =
0x060355040b13096c6f63616c686f7374311b301906035504031312436c69656e7420636572
74696669636174653121301f06092a864886f70d0109011612636c69656e74406578616d706c
652e636f6d820100300c0603551d13040530030101ff300d06092a864886f70d010104050003
81810033c00b66b1e579ef73a06798252dab8d5e5511fc00fd276d80d12f834777c6743fdc27
43fca1507704e4bc0979e4f60ac3ad9ee83e6f347369229d1f77229ba2e982359da563024a00
163dba6d6c986c0bad28af85132ff8f0d76501bf1b7c2dff658ce1e62c01997b6e64e3e8d437
3354ce9912847651539063b85bbc5485c516030100040e000000
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x39f344cd69a2f35503a380fcc8ea4a83
Finished request 3
Going to the next request
Waking up in 6 seconds...
rad_recv: Access-Request packet from host 141.2.252.203:62849, id=45,
length=283
        User-Name = "plisch01"
        State = 0x39f344cd69a2f35503a380fcc8ea4a83
        EAP-Message =
0x020400c01980000000b616030100861000008200805cf4ad6f145c089dc932b32a4c8c29f6
6f8ba762b19ca5e49d7fdcc56064623b8de51dc9f8eb186709c4c529f4c35dffc2c4d0868331
97659aea363231b79ef93008c66bc525ee5f83937f4a581566f4af250c15e7b9b4a931b04630
a359e665ac4f9497f9a60527d49ce0428e6b8005e2e2c44ce6617f35bf73370396429b641403
0100010116030100204729c2b650ffc91ec681e46eefe199e7405708a6fa89699d1e5d729b37
323e02
        Message-Authenticator = 0xe4a3fc40c382c15a35606865a372fc0c
        NAS-Identifier = "cb-jur-vc0-11og"
        NAS-Port-Type = Virtual
  Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 4
  modcall[authorize]: module "preprocess" returns ok for request 4
  modcall[authorize]: module "chap" returns noop for request 4
  modcall[authorize]: module "mschap" returns noop for request 4
    rlm_realm: No '@' in User-Name = "plisch01", looking up realm NULL
    rlm_realm: No such realm "NULL"
  modcall[authorize]: module "suffix" returns noop for request 4
  rlm_eap: EAP packet type response id 4 length 192
  rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
  modcall[authorize]: module "eap" returns updated for request 4
  modcall[authorize]: module "files" returns notfound for request 4
rlm_ldap: - authorize
rlm_ldap: performing user authorization for plisch01
radius_xlat:  '(uid=plisch01)'
radius_xlat:  'ou=XXX,ou=XXX,o=XXX,dc=XXX,dc=de'
rlm_ldap: ldap_get_conn: Checking Id: 0
rlm_ldap: ldap_get_conn: Got Id: 0
rlm_ldap: performing search in ou=XXX,ou=XXX,o=XXX,dc=XXX,dc=de, with filter
(uid=plisch01)
rlm_ldap: Added password 4183.... in check items
rlm_ldap: looking for check items in directory...
rlm_ldap: looking for reply items in directory...
rlm_ldap: user plisch01 authorized to use remote access
rlm_ldap: ldap_release_conn: Release Id: 0
  modcall[authorize]: module "ldap" returns ok for request 4
modcall: group authorize returns updated for request 4
  rad_check_password:  Found Auth-Type EAP
auth: type "EAP"
  Processing the authenticate section of radiusd.conf
modcall: entering group authenticate for request 4
  rlm_eap: Request found, released from the list
  rlm_eap: EAP/peap
  rlm_eap: processing type peap
  rlm_eap_peap: Authenticate
  rlm_eap_tls: processing TLS
rlm_eap_tls:  Length Included
  eaptls_verify returned 11 
  rlm_eap_tls: <<< TLS 1.0 Handshake [length 0086], ClientKeyExchange  
    TLS_accept: SSLv3 read client key exchange A 
  rlm_eap_tls: <<< TLS 1.0 ChangeCipherSpec [length 0001]  
  rlm_eap_tls: <<< TLS 1.0 Handshake [length 0010], Finished  
    TLS_accept: SSLv3 read finished A 
  rlm_eap_tls: >>> TLS 1.0 ChangeCipherSpec [length 0001]  
    TLS_accept: SSLv3 write change cipher spec A 
  rlm_eap_tls: >>> TLS 1.0 Handshake [length 0010], Finished  
    TLS_accept: SSLv3 write finished A 
    TLS_accept: SSLv3 flush data 
    (other): SSL negotiation finished successfully 
SSL Connection Established 
  eaptls_process returned 13 
  rlm_eap_peap: EAPTLS_HANDLED
  modcall[authenticate]: module "eap" returns handled for request 4
modcall: group authenticate returns handled for request 4
Sending Access-Challenge of id 45 to 141.2.252.203:62849
        EAP-Message =
0x01050031190014030100010116030100204b6baa9082446a5e5d949733bcd61cd97e71147f
4b7b0ede2fdf227003f80d63
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x283e48785e8097412f97fd724e4a6e25
Finished request 4
Going to the next request
--- Walking the entire request list ---
Waking up in 5 seconds...
rad_recv: Access-Request packet from host 141.2.252.203:62849, id=57,
length=97
        User-Name = "plisch01"
        State = 0x283e48785e8097412f97fd724e4a6e25
        EAP-Message = 0x020500061900
        Message-Authenticator = 0x322cc75005e5f7d756741b6b9db14083
        NAS-Identifier = "cb-jur-vc0-11og"
        NAS-Port-Type = Virtual
  Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 5
  modcall[authorize]: module "preprocess" returns ok for request 5
  modcall[authorize]: module "chap" returns noop for request 5
  modcall[authorize]: module "mschap" returns noop for request 5
    rlm_realm: No '@' in User-Name = "plisch01", looking up realm NULL
    rlm_realm: No such realm "NULL"
  modcall[authorize]: module "suffix" returns noop for request 5
  rlm_eap: EAP packet type response id 5 length 6
  rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
  modcall[authorize]: module "eap" returns updated for request 5
  modcall[authorize]: module "files" returns notfound for request 5
rlm_ldap: - authorize
rlm_ldap: performing user authorization for plisch01
radius_xlat:  '(uid=plisch01)'
radius_xlat:  'ou=XXX,ou=XXX,o=XXX,dc=XXX,dc=de'
rlm_ldap: ldap_get_conn: Checking Id: 0
rlm_ldap: ldap_get_conn: Got Id: 0
rlm_ldap: performing search in ou=XXX,ou=XXX,o=XXX,dc=XXX,dc=de, with filter
(uid=plisch01)
rlm_ldap: Added password 4183... in check items
rlm_ldap: looking for check items in directory...
rlm_ldap: looking for reply items in directory...
rlm_ldap: user plisch01 authorized to use remote access
rlm_ldap: ldap_release_conn: Release Id: 0
  modcall[authorize]: module "ldap" returns ok for request 5
modcall: group authorize returns updated for request 5
  rad_check_password:  Found Auth-Type EAP
auth: type "EAP"
  Processing the authenticate section of radiusd.conf
modcall: entering group authenticate for request 5
  rlm_eap: Request found, released from the list
  rlm_eap: EAP/peap
  rlm_eap: processing type peap
  rlm_eap_peap: Authenticate
  rlm_eap_tls: processing TLS
rlm_eap_tls: Received EAP-TLS ACK message
  rlm_eap_tls: ack handshake is finished
  eaptls_verify returned 3 
  eaptls_process returned 3 
  rlm_eap_peap: EAPTLS_SUCCESS
  modcall[authenticate]: module "eap" returns handled for request 5
modcall: group authenticate returns handled for request 5
Sending Access-Challenge of id 57 to 141.2.252.203:62849
        EAP-Message =
0x010600201900170301001515b983ce613f1d101b1b0c3e9f632bc2bdd92bf0ef
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x3ee625007e53c68d653aa899c99579c1
Finished request 5
Going to the next request
Waking up in 5 seconds...
rad_recv: Access-Request packet from host 141.2.252.203:62849, id=147,
length=127
        User-Name = "plisch01"
        State = 0x3ee625007e53c68d653aa899c99579c1
        EAP-Message =
0x020600241900170301001920ce664e444ad38f8d09783ae8c77e4e6891969c2973856cff
        Message-Authenticator = 0xe7234912513e897b42b52724e518927e
        NAS-Identifier = "cb-jur-vc0-11og"
        NAS-Port-Type = Virtual
  Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 6
  modcall[authorize]: module "preprocess" returns ok for request 6
  modcall[authorize]: module "chap" returns noop for request 6
  modcall[authorize]: module "mschap" returns noop for request 6
    rlm_realm: No '@' in User-Name = "plisch01", looking up realm NULL
    rlm_realm: No such realm "NULL"
  modcall[authorize]: module "suffix" returns noop for request 6
  rlm_eap: EAP packet type response id 6 length 36
  rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
  modcall[authorize]: module "eap" returns updated for request 6
  modcall[authorize]: module "files" returns notfound for request 6
rlm_ldap: - authorize
rlm_ldap: performing user authorization for plisch01
radius_xlat:  '(uid=plisch01)'
radius_xlat:  'ou=XXX,ou=XXX,o=XXX,dc=XXX,dc=de'
rlm_ldap: ldap_get_conn: Checking Id: 0
rlm_ldap: ldap_get_conn: Got Id: 0
rlm_ldap: performing search in ou=XXX,ou=XXX,o=XXX,dc=XXX,dc=de, with filter
(uid=plisch01)
rlm_ldap: Added password 4183.... in check items
rlm_ldap: looking for check items in directory...
rlm_ldap: looking for reply items in directory...
rlm_ldap: user plisch01 authorized to use remote access
rlm_ldap: ldap_release_conn: Release Id: 0
  modcall[authorize]: module "ldap" returns ok for request 6
modcall: group authorize returns updated for request 6
  rad_check_password:  Found Auth-Type EAP
auth: type "EAP"
  Processing the authenticate section of radiusd.conf
modcall: entering group authenticate for request 6
  rlm_eap: Request found, released from the list
  rlm_eap: EAP/peap
  rlm_eap: processing type peap
  rlm_eap_peap: Authenticate
  rlm_eap_tls: processing TLS
  eaptls_verify returned 7 
  rlm_eap_tls: Done initial handshake
  eaptls_process returned 7 
  rlm_eap_peap: EAPTLS_OK
  rlm_eap_peap: Session established.  Decoding tunneled attributes.
  rlm_eap_peap: Identity - plisch01
  rlm_eap_peap: Tunneled data is valid.
  PEAP: Got tunneled EAP-Message
        EAP-Message = 0x0206000d01706c697363683031
  PEAP: Got tunneled identity of plisch01
  PEAP: Setting default EAP type for tunneled EAP session.
  PEAP: Setting User-Name to plisch01
  PEAP: Sending tunneled request
        EAP-Message = 0x0206000d01706c697363683031
        FreeRADIUS-Proxied-To = 127.0.0.1
        User-Name = "plisch01"
  Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 6
  modcall[authorize]: module "preprocess" returns ok for request 6
  modcall[authorize]: module "chap" returns noop for request 6
  modcall[authorize]: module "mschap" returns noop for request 6
    rlm_realm: No '@' in User-Name = "plisch01", looking up realm NULL
    rlm_realm: No such realm "NULL"
  modcall[authorize]: module "suffix" returns noop for request 6
  rlm_eap: EAP packet type response id 6 length 13
  rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
  modcall[authorize]: module "eap" returns updated for request 6
    users: Matched DEFAULT at 244
radius_xlat:  'plisch01'
  modcall[authorize]: module "files" returns ok for request 6
rlm_ldap: - authorize
rlm_ldap: performing user authorization for plisch01
radius_xlat:  '(uid=plisch01)'
radius_xlat:  'ou=XXX,ou=XXX,o=XXX,dc=XXX,dc=de'
rlm_ldap: ldap_get_conn: Checking Id: 0
rlm_ldap: ldap_get_conn: Got Id: 0
rlm_ldap: performing search in ou=XXX,ou=XXX,o=XXX,dc=XXX,dc=de, with filter
(uid=plisch01)
rlm_ldap: Added password 4183.... in check items
rlm_ldap: looking for check items in directory...
rlm_ldap: looking for reply items in directory...
rlm_ldap: user plisch01 authorized to use remote access
rlm_ldap: ldap_release_conn: Release Id: 0
  modcall[authorize]: module "ldap" returns ok for request 6
modcall: group authorize returns updated for request 6
  rad_check_password:  Found Auth-Type EAP
auth: type "EAP"
  Processing the authenticate section of radiusd.conf
modcall: entering group authenticate for request 6
  rlm_eap: EAP Identity
  rlm_eap: processing type mschapv2
rlm_eap_mschapv2: Issuing Challenge
  modcall[authenticate]: module "eap" returns handled for request 6
modcall: group authenticate returns handled for request 6
  PEAP: Got tunneled reply RADIUS code 11
        User-Name = "plisch01"
        EAP-Message =
0x010700221a0107001d105fe75feb133da90be571a2ab66b56b41706c697363683031
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x5d10815c41541ad37a91292eea4550b6
  PEAP: Processing from tunneled session code 0x90f6918 11
        User-Name = "plisch01"
        EAP-Message =
0x010700221a0107001d105fe75feb133da90be571a2ab66b56b41706c697363683031
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x5d10815c41541ad37a91292eea4550b6
  PEAP: Got tunneled Access-Challenge
  modcall[authenticate]: module "eap" returns handled for request 6
modcall: group authenticate returns handled for request 6
Sending Access-Challenge of id 147 to 141.2.252.203:62849
        EAP-Message =
0x010700391900170301002ec95e5e434f311c9c7cbd1b8eeea7bd19d9078f4cffcfd930a088
ad9a6318e723477696e13974f1fc1101894571e4
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0xf75459f95978ea5dee485ccbf6b9ad9a
Finished request 6
Going to the next request
Waking up in 5 seconds...
rad_recv: Access-Request packet from host 141.2.252.203:62849, id=70,
length=181
        User-Name = "plisch01"
        State = 0xf75459f95978ea5dee485ccbf6b9ad9a
        EAP-Message =
0x0207005a1900170301004f491c7ee6409ec5ae6769e0c33d4f7062f03a24ef9c951fc1b00b
7204a7e10e2cc5d9a1ff9c3b8f6dbb71d8f4b3d69bf7a710d6019376d6a370b59671d11de1cb
9cf688c434a68ad7d5281e6cfd8d46
        Message-Authenticator = 0x0a9cf79ba8ea337330e56aa8b0785547
        NAS-Identifier = "cb-jur-vc0-11og"
        NAS-Port-Type = Virtual
  Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 7
  modcall[authorize]: module "preprocess" returns ok for request 7
  modcall[authorize]: module "chap" returns noop for request 7
  modcall[authorize]: module "mschap" returns noop for request 7
    rlm_realm: No '@' in User-Name = "plisch01", looking up realm NULL
    rlm_realm: No such realm "NULL"
  modcall[authorize]: module "suffix" returns noop for request 7
  rlm_eap: EAP packet type response id 7 length 90
  rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
  modcall[authorize]: module "eap" returns updated for request 7
  modcall[authorize]: module "files" returns notfound for request 7
rlm_ldap: - authorize
rlm_ldap: performing user authorization for plisch01
radius_xlat:  '(uid=plisch01)'
radius_xlat:  'ou=XXX,ou=XXX,o=XXX,dc=XXX,dc=de'
rlm_ldap: ldap_get_conn: Checking Id: 0
rlm_ldap: ldap_get_conn: Got Id: 0
rlm_ldap: performing search in ou=raduser,ou=XXX,o=XXX,dc=XXX,dc=de, with
filter (uid=plisch01)
rlm_ldap: Added password 4183.... in check items
rlm_ldap: looking for check items in directory...
rlm_ldap: looking for reply items in directory...
rlm_ldap: user plisch01 authorized to use remote access
rlm_ldap: ldap_release_conn: Release Id: 0
  modcall[authorize]: module "ldap" returns ok for request 7
modcall: group authorize returns updated for request 7
  rad_check_password:  Found Auth-Type EAP
auth: type "EAP"
  Processing the authenticate section of radiusd.conf
modcall: entering group authenticate for request 7
  rlm_eap: Request found, released from the list
  rlm_eap: EAP/peap
  rlm_eap: processing type peap
  rlm_eap_peap: Authenticate
  rlm_eap_tls: processing TLS
  eaptls_verify returned 7 
  rlm_eap_tls: Done initial handshake
  eaptls_process returned 7 
  rlm_eap_peap: EAPTLS_OK
  rlm_eap_peap: Session established.  Decoding tunneled attributes.
  rlm_eap_peap: EAP type mschapv2
  rlm_eap_peap: Tunneled data is valid.
  PEAP: Got tunneled EAP-Message
        EAP-Message =
0x020700431a0207003e3168e3bcd95cb641bff66d420b10b07cd80000000000000000307384
bc22ffe588803cf80f47635e7c4d43fe726c920d6700706c697363683031
  PEAP: Setting User-Name to plisch01
  PEAP: Adding old state with 5d 10
  PEAP: Sending tunneled request
        EAP-Message =
0x020700431a0207003e3168e3bcd95cb641bff66d420b10b07cd80000000000000000307384
bc22ffe588803cf80f47635e7c4d43fe726c920d6700706c697363683031
        FreeRADIUS-Proxied-To = 127.0.0.1
        User-Name = "plisch01"
        State = 0x5d10815c41541ad37a91292eea4550b6
  Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 7
  modcall[authorize]: module "preprocess" returns ok for request 7
  modcall[authorize]: module "chap" returns noop for request 7
  modcall[authorize]: module "mschap" returns noop for request 7
    rlm_realm: No '@' in User-Name = "plisch01", looking up realm NULL
    rlm_realm: No such realm "NULL"
  modcall[authorize]: module "suffix" returns noop for request 7
  rlm_eap: EAP packet type response id 7 length 67
  rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
  modcall[authorize]: module "eap" returns updated for request 7
    users: Matched DEFAULT at 244
radius_xlat:  'plisch01'
  modcall[authorize]: module "files" returns ok for request 7
rlm_ldap: - authorize
rlm_ldap: performing user authorization for plisch01
radius_xlat:  '(uid=plisch01)'
radius_xlat:  'ou=XXX,ou=XXX,o=XXX,dc=XXX,dc=de'
rlm_ldap: ldap_get_conn: Checking Id: 0
rlm_ldap: ldap_get_conn: Got Id: 0
rlm_ldap: performing search in ou=XXX,ou=XXX,o=XXX,dc=XXX,dc=de, with filter
(uid=plisch01)
rlm_ldap: Added password 4183.... in check items
rlm_ldap: looking for check items in directory...
rlm_ldap: looking for reply items in directory...
rlm_ldap: user plisch01 authorized to use remote access
rlm_ldap: ldap_release_conn: Release Id: 0
  modcall[authorize]: module "ldap" returns ok for request 7
modcall: group authorize returns updated for request 7
  rad_check_password:  Found Auth-Type EAP
auth: type "EAP"
  Processing the authenticate section of radiusd.conf
modcall: entering group authenticate for request 7
  rlm_eap: Request found, released from the list
  rlm_eap: EAP/mschapv2
  rlm_eap: processing type mschapv2
  Processing the authenticate section of radiusd.conf
modcall: entering group Auth-Type for request 7
  rlm_mschap: Told to do MS-CHAPv2 for plisch01 with NT-Password
  rlm_mschap: FAILED: MS-CHAP2-Response is incorrect
  modcall[authenticate]: module "mschap" returns reject for request 7
modcall: group Auth-Type returns reject for request 7
  rlm_eap: Freeing handler
  modcall[authenticate]: module "eap" returns reject for request 7
modcall: group authenticate returns reject for request 7
auth: Failed to validate the user.
Login incorrect: [plisch01] (from client localhost port 0)
  PEAP: Got tunneled reply RADIUS code 3
        User-Name = "plisch01"
        MS-CHAP-Error = "\007E=691 R=1"
        EAP-Message = 0x04070004
        Message-Authenticator = 0x00000000000000000000000000000000
  PEAP: Processing from tunneled session code 0x90f60d0 3
        User-Name = "plisch01"
        MS-CHAP-Error = "\007E=691 R=1"
        EAP-Message = 0x04070004
        Message-Authenticator = 0x00000000000000000000000000000000
  PEAP: Tunneled authentication was rejected.
  rlm_eap_peap: FAILURE
  modcall[authenticate]: module "eap" returns handled for request 7
modcall: group authenticate returns handled for request 7
Sending Access-Challenge of id 70 to 141.2.252.203:62849
        EAP-Message =
0x010800261900170301001b1aaec581089b9d3dbc54fb36761fbe248d25e2663ca7476b4971
b5
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x0826aec91672e96341cd1b93cca166c5
Finished request 7
Going to the next request
Waking up in 5 seconds...
rad_recv: Access-Request packet from host 141.2.252.203:62849, id=1,
length=129
        User-Name = "plisch01"
        State = 0x0826aec91672e96341cd1b93cca166c5
        EAP-Message =
0x020800261900170301001bc8df9767d6720bbf4aa9ba81c8c6749d20979bf65f4d20e3a862
59
        Message-Authenticator = 0x78b71176e4eccdb35ecb960b32ec0a0a
        NAS-Identifier = "cb-jur-vc0-11og"
        NAS-Port-Type = Virtual
  Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 8
  modcall[authorize]: module "preprocess" returns ok for request 8
  modcall[authorize]: module "chap" returns noop for request 8
  modcall[authorize]: module "mschap" returns noop for request 8
    rlm_realm: No '@' in User-Name = "plisch01", looking up realm NULL
    rlm_realm: No such realm "NULL"
  modcall[authorize]: module "suffix" returns noop for request 8
  rlm_eap: EAP packet type response id 8 length 38
  rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
  modcall[authorize]: module "eap" returns updated for request 8
  modcall[authorize]: module "files" returns notfound for request 8
rlm_ldap: - authorize
rlm_ldap: performing user authorization for plisch01
radius_xlat:  '(uid=plisch01)'
radius_xlat:  'ou=XXX,ou=XXX,o=XXX,dc=XXX,dc=de'
rlm_ldap: ldap_get_conn: Checking Id: 0
rlm_ldap: ldap_get_conn: Got Id: 0
rlm_ldap: performing search in ou=XXX,ou=XXX,o=XXX,dc=XXX,dc=de, with filter
(uid=plisch01)
rlm_ldap: Added password 4183.... in check items
rlm_ldap: looking for check items in directory...
rlm_ldap: looking for reply items in directory...
rlm_ldap: user plisch01 authorized to use remote access
rlm_ldap: ldap_release_conn: Release Id: 0
  modcall[authorize]: module "ldap" returns ok for request 8
modcall: group authorize returns updated for request 8
  rad_check_password:  Found Auth-Type EAP
auth: type "EAP"
  Processing the authenticate section of radiusd.conf
modcall: entering group authenticate for request 8
  rlm_eap: Request found, released from the list
  rlm_eap: EAP/peap
  rlm_eap: processing type peap
  rlm_eap_peap: Authenticate
  rlm_eap_tls: processing TLS
  eaptls_verify returned 7 
  rlm_eap_tls: Done initial handshake
  eaptls_process returned 7 
  rlm_eap_peap: EAPTLS_OK
  rlm_eap_peap: Session established.  Decoding tunneled attributes.
  rlm_eap_peap: Received EAP-TLV response.
  rlm_eap_peap: Tunneled data is valid.
  rlm_eap_peap:  Had sent TLV failure, rejecting.
 rlm_eap: Handler failed in EAP/peap
  rlm_eap: Failed in EAP select
  modcall[authenticate]: module "eap" returns invalid for request 8
modcall: group authenticate returns invalid for request 8
auth: Failed to validate the user.
Login incorrect: [plisch01] (from client Juniper-EX port 0)
Delaying request 8 for 1 seconds
Finished request 8
Going to the next request
Waking up in 5 seconds...
rad_recv: Access-Request packet from host 141.2.252.203:62849, id=1,
length=129
Sending Access-Reject of id 1 to 141.2.252.203:62849
        EAP-Message = 0x04080004
        Message-Authenticator = 0x00000000000000000000000000000000
--- Walking the entire request list ---
Waking up in 2 seconds...
--- Walking the entire request list ---
Cleaning up request 3 ID 12 with timestamp 496755f3
Cleaning up request 2 ID 131 with timestamp 496755f3
Cleaning up request 0 ID 206 with timestamp 496755f3
Cleaning up request 1 ID 229 with timestamp 496755f3
Waking up in 1 seconds...
--- Walking the entire request list ---
Cleaning up request 8 ID 1 with timestamp 496755f4
Cleaning up request 4 ID 45 with timestamp 496755f4
Cleaning up request 5 ID 57 with timestamp 496755f4
Cleaning up request 7 ID 70 with timestamp 496755f4
Cleaning up request 6 ID 147 with timestamp 496755f4
Nothing to do.  Sleeping until we see a request.
</radiusd -X>

Authentication Problem with PEAP and openldap

Michael Poser