ERROR! Our request for peap was NAK'd with a request for peap

Rob Yamry ryamry at kimberly.k12.wi.us
Thu Dec 9 19:25:32 CET 2010


I have a HP JetDirect 690n print server that Im trying to authenticate via
FreeRadius 2.1.8 for wireless clients to use.  If I tell the 690 to use peap
then I get the error "ERROR! Our request for peap was NAK'd with a request
for peap".  If I tell it to use eap-tls I get the error "ERROR! Our request
for tls was NAK'd with a request for tls".  Also, I have a user setup in the
users file, but it still tries to search ldap for that user.  I can login
fine with the local "ktest" user via radtest or ntradping.  Debug log from a
peap request is here:

Ready to process requests.
rad_recv: Access-Request packet from host 10.1.1.1 port 47567, id=80,
length=283
        User-Name = "ktest"
        NAS-IP-Address = 10.1.1.1
        NAS-Port = 150
        Framed-MTU = 1400
        Called-Station-Id = "00:1f:45:7f:83:fa"
        Calling-Station-Id = "00:1b:78:eb:c8:1d"
        NAS-Port-Type = Wireless-802.11
        NAS-Identifier = "TEST"
        Siemens-AP-Serial = "0500010143052305"
        Siemens-AP-Name = "AP01"
        Siemens-VNS-Name = "TEST"
        Siemens-BSSID = "TEST"
        Siemens-BSS-MAC = "00:1f:45:7f:83:fa"
        Siemens-Policy = "NonAuth"
        Siemens-Topology = "Bridged at AP untagged"
        EAP-Message = 0x0201000a016b74657374
        Message-Authenticator = 0xef83aea844bdbfb74c34110c7fafa33f
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
[suffix] No '@' in User-Name = "ktest", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 1 length 10
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
++[unix] returns notfound
[files] users: Matched entry ktest at line 209
++[files] returns ok
[ldap] performing user authorization for ktest
[ldap] WARNING: Deprecated conditional expansion ":-".  See "man unlang" for
details
[ldap]  ... expanding second conditional
[ldap]  expand: %{User-Name} -> ktest
[ldap]  expand: (cn=%{Stripped-User-Name:-%{User-Name}}) -> (cn=ktest)
[ldap]  expand: o=org -> o=org
  [ldap] ldap_get_conn: Checking Id: 0
  [ldap] ldap_get_conn: Got Id: 0
  [ldap] attempting LDAP reconnection
  [ldap] (re)connect to ldap.company.com:389, authentication 0
  [ldap] setting TLS CACert File to /etc/raddb/certs/ca.pem
  [ldap] starting TLS
  [ldap] bind as cn=radmin,o=org/<password> to ldap.company.com:389
  [ldap] waiting for bind result ...
  [ldap] Bind was successful
  [ldap] performing search in o=org, with filter (cn=ktest)
  [ldap] object not found
[ldap] search failed
  [ldap] ldap_release_conn: Release Id: 0
++[ldap] returns notfound
++[expiration] returns noop
++[logintime] returns noop
[pap] Found existing Auth-Type, not changing it.
++[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 80 to 10.1.1.1 port 47567
        Filter-Id = "Students"
        EAP-Message = 0x010200061920
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0xb21c3f23b21e261bc6f5440efd9d3572
Finished request 0.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.1.1.1 port 47567, id=80,
length=361
Cleaning up request 0 ID 80 with timestamp +53
        User-Name = "ktest"
        NAS-IP-Address = 10.1.1.1
        NAS-Port = 150
        Framed-MTU = 1400
        Called-Station-Id = "00:1f:45:7f:83:fa"
        Calling-Station-Id = "00:1b:78:eb:c8:1d"
        NAS-Port-Type = Wireless-802.11
        NAS-Identifier = "TEST"
        Siemens-AP-Serial = "0500010143052305"
        Siemens-AP-Name = "AP01"
        Siemens-VNS-Name = "TEST"
        Siemens-BSSID = "TEST"
        Siemens-BSS-MAC = "00:1f:45:7f:83:fa"
        Siemens-Policy = "NonAuth"
        Siemens-Topology = "Bridged at AP untagged"
        EAP-Message =
0x0202004619800000003c16030100370100003303010000000c2db78264c7293dabf829a390628548921ccd153f66aef981c50d964c00000c0035000a002f0005000400090100
        State = 0xb21c3f23b21e261bc6f5440efd9d3572
        Message-Authenticator = 0x047a88b42dd297aff674849e11cc719b
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
[suffix] No '@' in User-Name = "ktest", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 2 length 70
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/peap
[eap] processing type peap
[peap] processing EAP-TLS
  TLS Length 60
[peap] Length Included
[peap] eaptls_verify returned 11
[peap]     (other): before/accept initialization
[peap]     TLS_accept: before/accept initialization
[peap] <<< TLS 1.0 Handshake [length 0037], ClientHello
[peap]     TLS_accept: SSLv3 read client hello A
[peap] >>> TLS 1.0 Handshake [length 002a], ServerHello
[peap]     TLS_accept: SSLv3 write server hello A
[peap] >>> TLS 1.0 Handshake [length 0b95], Certificate
[peap]     TLS_accept: SSLv3 write certificate A
[peap] >>> TLS 1.0 Handshake [length 0004], ServerHelloDone
[peap]     TLS_accept: SSLv3 write server done A
[peap]     TLS_accept: SSLv3 flush data
[peap]     TLS_accept: Need to read more data: SSLv3 read client certificate
A
In SSL Handshake Phase
In SSL Accept mode
[peap] eaptls_process returned 13
[peap] EAPTLS_HANDLED
++[eap] returns handled
Sending Access-Challenge of id 80 to 10.1.1.1 port 47567
        EAP-Message =
0x0103040019c000000bd2160301002a0200002603014cffb1ebbcc5475dcfc501c476c4728d86282b97d10966cfc06dd18a38bbef7f000035001603010b950b000b91000b8e0005b1308205ad30820495a003020102020103300d06092a864886f70d01010505003081c0310b3009060355040613025553310b30090603550408130257493111300f060355040713084b696d6265726c7931263024060355040a131d4b696d6265726c792041726561205363686f6f6c204469737472696374313c303a060355040313334b696d6265726c792041726561205363686f6f6c20446973747269637420436572746966696361746520417574686f72697479
        EAP-Message =
0x312b302906092a864886f70d010901161c7765626d6173746572406b696d6265726c792e6b31322e77692e7573301e170d3130303331363133333732345a170d3137303331343133333732345a3081a4310b3009060355040613025553310b30090603550408130257493111300f060355040713084b696d6265726c7931263024060355040a131d4b696d6265726c792041726561205363686f6f6c2044697374726963743120301e060355040313176c6461702e6b696d6265726c792e6b31322e77692e7573312b302906092a864886f70d010901161c7765626d6173746572406b696d6265726c792e6b31322e77692e757330820122300d06092a
        EAP-Message =
0x864886f70d01010105000382010f003082010a0282010100cad3696f20cbdc165ddd4dfdf8f4a1b96a1d4aca94548853d895b8e72a29d078e7fa69b4962adc66d2b8db9f8bcb9e49df313a06dabdbecca170d1a2a93341b2cffede3c8675053b9617aca00de9c263de036840e0982133f2e7972357662d6acd876ebfce2e14f7dc1408380fc802d6f0100d8014d7e818e59dda1307f59d5bcf2d861a54a28af634697fa10ce3ed1be9a95199a49a94c7fdf0b97a3e2bbc37b5aed07e002035f97d5231ba880ab7022ccf3e9b875654cd2dfde3d75558ad4287a29c74cfef1dfe9354c6a9f904ebff2c9b4d26b5f7ec4ff0da63fc2fe8c8171c029acbd4
        EAP-Message =
0x97e9a89184d0bd309837c787de2c0af4f43773ccce11cfdb3aaeb50203010001a38201ca308201c630090603551d1304023000303006096086480186f842010d04231621596153542047656e65726174656420536572766572204365727469666963617465301106096086480186f8420101040403020640300b0603551d0f0404030205a0301d0603551d0e0416041467eabf6541c39d4ed474b25d1d42b4a40641ef053081f50603551d230481ed3081ea8014cb6f25029dcbc68e70aeff2fa9a9baee6af47f77a181c6a481c33081c0310b3009060355040613025553310b30090603550408130257493111300f060355040713084b696d6265726c
        EAP-Message = 0x7931263024060355040a131d
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0xb21c3f23b31f261bc6f5440efd9d3572
Finished request 1.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.1.1.1 port 47567, id=80,
length=297
Cleaning up request 1 ID 80 with timestamp +54
        User-Name = "ktest"
        NAS-IP-Address = 10.1.1.1
        NAS-Port = 150
        Framed-MTU = 1400
        Called-Station-Id = "00:1f:45:7f:83:fa"
        Calling-Station-Id = "00:1b:78:eb:c8:1d"
        NAS-Port-Type = Wireless-802.11
        NAS-Identifier = "TEST"
        Siemens-AP-Serial = "0500010143052305"
        Siemens-AP-Name = "AP01"
        Siemens-VNS-Name = "TEST"
        Siemens-BSSID = "TEST"
        Siemens-BSS-MAC = "00:1f:45:7f:83:fa"
        Siemens-Policy = "NonAuth"
        Siemens-Topology = "Bridged at AP untagged"
        EAP-Message = 0x020300061900
        State = 0xb21c3f23b31f261bc6f5440efd9d3572
        Message-Authenticator = 0xce8fce3cab0d91febe1a2b82b5f43071
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
[suffix] No '@' in User-Name = "ktest", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 3 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/peap
[eap] processing type peap
[peap] processing EAP-TLS
[peap] Received TLS ACK
[peap] ACK handshake fragment handler
[peap] eaptls_verify returned 1
[peap] eaptls_process returned 13
[peap] EAPTLS_HANDLED
++[eap] returns handled
Sending Access-Challenge of id 80 to 10.1.1.1 port 47567
        EAP-Message =
0x010403fc19404b696d6265726c792041726561205363686f6f6c204469737472696374313c303a060355040313334b696d6265726c792041726561205363686f6f6c20446973747269637420436572746966696361746520417574686f72697479312b302906092a864886f70d010901161c7765626d6173746572406b696d6265726c792e6b31322e77692e7573820900d6d85d886ad5a6f830270603551d110420301e811c7765626d6173746572406b696d6265726c792e6b31322e77692e757330270603551d120420301e811c7765626d6173746572406b696d6265726c792e6b31322e77692e7573300d06092a864886f70d0101050500038201
        EAP-Message =
0x01003f8292ee1e98c0595f0da2e0692d632b818fdef25f4ef7e4b6748c075fc7ca14f22ce2de91d9e407ee786de26e2be17f1208470e3480374ef3ba826f5c55a42e1b3e229008322e04b72781f73ef22e2404561731f03da7c07cb80dcabbdcc0bc5c6fd3da0f4f3cfd8a54d17041a4b675a09d99845f6af40ed129299427a11d34c5551142232eef7c36ef1e8d95e695057d6dd7450b27359b5a89663b910934d28977bb80ed5430b4dc92022622f56a00e4143d507701b7dc49ff5bb7e46db5621c0667cc15d480ae1ecb764bb89c0c255d5b874e31e484293b823056cf9cbc8bc94015bb8d99db0571cbbfb49ab775a6de4d98da36df016ac968ff
        EAP-Message =
0x4b78507d900005d7308205d3308204bba003020102020900d6d85d886ad5a6f8300d06092a864886f70d01010505003081c0310b3009060355040613025553310b30090603550408130257493111300f060355040713084b696d6265726c7931263024060355040a131d4b696d6265726c792041726561205363686f6f6c204469737472696374313c303a060355040313334b696d6265726c792041726561205363686f6f6c20446973747269637420436572746966696361746520417574686f72697479312b302906092a864886f70d010901161c7765626d6173746572406b696d6265726c792e6b31322e77692e7573301e170d31303033313631
        EAP-Message =
0x33333331375a170d3230303331333133333331375a3081c0310b3009060355040613025553310b30090603550408130257493111300f060355040713084b696d6265726c7931263024060355040a131d4b696d6265726c792041726561205363686f6f6c204469737472696374313c303a060355040313334b696d6265726c792041726561205363686f6f6c20446973747269637420436572746966696361746520417574686f72697479312b302906092a864886f70d010901161c7765626d6173746572406b696d6265726c792e6b31322e77692e757330820122300d06092a864886f70d01010105000382010f003082010a0282010100d551d5fb
        EAP-Message = 0xb0e4092778a12e41
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0xb21c3f23b018261bc6f5440efd9d3572
Finished request 2.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.1.1.1 port 47567, id=80,
length=297
Cleaning up request 2 ID 80 with timestamp +54
        User-Name = "ktest"
        NAS-IP-Address = 10.1.1.1
        NAS-Port = 150
        Framed-MTU = 1400
        Called-Station-Id = "00:1f:45:7f:83:fa"
        Calling-Station-Id = "00:1b:78:eb:c8:1d"
        NAS-Port-Type = Wireless-802.11
        NAS-Identifier = "TEST"
        Siemens-AP-Serial = "0500010143052305"
        Siemens-AP-Name = "AP01"
        Siemens-VNS-Name = "TEST"
        Siemens-BSSID = "TEST"
        Siemens-BSS-MAC = "00:1f:45:7f:83:fa"
        Siemens-Policy = "NonAuth"
        Siemens-Topology = "Bridged at AP untagged"
        EAP-Message = 0x020400061900
        State = 0xb21c3f23b018261bc6f5440efd9d3572
        Message-Authenticator = 0x552a1288d35108114eb710baa5d4e06d
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
[suffix] No '@' in User-Name = "ktest", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 4 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/peap
[eap] processing type peap
[peap] processing EAP-TLS
[peap] Received TLS ACK
[peap] ACK handshake fragment handler
[peap] eaptls_verify returned 1
[peap] eaptls_process returned 13
[peap] EAPTLS_HANDLED
++[eap] returns handled
Sending Access-Challenge of id 80 to 10.1.1.1 port 47567
        EAP-Message =
0x010503ec1900659f48472b8d2d5d9a8da76c445e33490bee5c5c155fe88108113ed74335a2ba068e51f7da1fa2c4ac8a156f3c5da7c0e1df69a27b32f3825880b80eff9cd02c2f3beeb9669ae0fea448d28da8498d9d227087fa2199c15dd80e9a6477e64fdb8b138265605f5ad61581084b9d7faa0deb343f6697ace0d0bdd3908736544251650239d0707fedf29c465e4bcecc92034249c23123dea30a5c85ed92f6d0475830555550d0997d1152892bb8ff7d7bd148652d69c1bcc014371df36e2f3a075b1f5f165dcdd816cb5e7750d6f6dd4ed1e4494cb0f050c53c0397f03e195d67f1d2f3dec0fc4a198d32775e34530ccf191e522cb3020301
        EAP-Message =
0x0001a38201cc308201c8300f0603551d130101ff040530030101ff302c06096086480186f842010d041f161d596153542047656e657261746564204341204365727469666963617465301106096086480186f8420101040403020106300b0603551d0f040403020106301d0603551d0e04160414cb6f25029dcbc68e70aeff2fa9a9baee6af47f773081f50603551d230481ed3081ea8014cb6f25029dcbc68e70aeff2fa9a9baee6af47f77a181c6a481c33081c0310b3009060355040613025553310b30090603550408130257493111300f060355040713084b696d6265726c7931263024060355040a131d4b696d6265726c792041726561205363
        EAP-Message =
0x686f6f6c204469737472696374313c303a060355040313334b696d6265726c792041726561205363686f6f6c20446973747269637420436572746966696361746520417574686f72697479312b302906092a864886f70d010901161c7765626d6173746572406b696d6265726c792e6b31322e77692e7573820900d6d85d886ad5a6f830270603551d110420301e811c7765626d6173746572406b696d6265726c792e6b31322e77692e757330270603551d120420301e811c7765626d6173746572406b696d6265726c792e6b31322e77692e7573300d06092a864886f70d010105050003820101004b96358c5945bbc3937219dc3371b00431ab3b6e
        EAP-Message =
0x67be20fd70177edba50c23cbe05be70995474416cc6562174c08602e4d075e8fd648a90b72be087d25fba87d2442973a4651da2690b02aab44222cc8336b8acf2d387b7606f5bb7a4f360e9381fc79c28535ff23aab2e3d2f31544a34f8ae2805ac32e6592ab7c9a090ddd1e15f7aba6a3c7758723b634d47dc7109564708bf0b30f04f55a6ea1ab28787407f33e0997412709d970d2fd79a4a5826967c41db74eb68bac6c309d1f1fe2b16fa0d18a5352159ac1bd7c29cbdf787ec92deb3d84cd27c32b351b8023f79f97a5e0b970b9fdb4456a626d87cbe45f1c36d580cbd51ff1572a27f7e5555ef8195e16030100040e000000
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0xb21c3f23b119261bc6f5440efd9d3572
Finished request 3.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.1.1.1 port 47567, id=80,
length=297
Cleaning up request 3 ID 80 with timestamp +54
        User-Name = "ktest"
        NAS-IP-Address = 10.1.1.1
        NAS-Port = 150
        Framed-MTU = 1400
        Called-Station-Id = "00:1f:45:7f:83:fa"
        Calling-Station-Id = "00:1b:78:eb:c8:1d"
        NAS-Port-Type = Wireless-802.11
        NAS-Identifier = "TEST"
        Siemens-AP-Serial = "0500010143052305"
        Siemens-AP-Name = "AP01"
        Siemens-VNS-Name = "TEST"
        Siemens-BSSID = "TEST"
        Siemens-BSS-MAC = "00:1f:45:7f:83:fa"
        Siemens-Policy = "NonAuth"
        Siemens-Topology = "Bridged at AP untagged"
        EAP-Message = 0x020500060319
        State = 0xb21c3f23b119261bc6f5440efd9d3572
        Message-Authenticator = 0xbb238eafebdfefd81192fb93cacdb01c
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
[suffix] No '@' in User-Name = "ktest", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 5 length 6
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
++[unix] returns notfound
[files] users: Matched entry ktest at line 209
++[files] returns ok
[ldap] performing user authorization for ktest
[ldap] WARNING: Deprecated conditional expansion ":-".  See "man unlang" for
details
[ldap]  ... expanding second conditional
[ldap]  expand: %{User-Name} -> ktest
[ldap]  expand: (cn=%{Stripped-User-Name:-%{User-Name}}) -> (cn=ktest)
[ldap]  expand: o=org -> o=org
  [ldap] ldap_get_conn: Checking Id: 0
  [ldap] ldap_get_conn: Got Id: 0
  [ldap] performing search in o=org, with filter (cn=ktest)
  [ldap] object not found
[ldap] search failed
  [ldap] ldap_release_conn: Release Id: 0
++[ldap] returns notfound
++[expiration] returns noop
++[logintime] returns noop
[pap] Found existing Auth-Type, not changing it.
++[pap] returns noop
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP NAK
[eap] ERROR! Our request for peap was NAK'd with a request for peap.
Skipping the requested type.
[eap] No common EAP types found.
[eap] Failed in EAP select
++[eap] returns invalid
Failed to authenticate the user.
Login incorrect (  [ldap] User not found): [ktest/<via Auth-Type = EAP>]
(from client kasd port 150 cli 00:1b:78:eb:c8:1d)
Using Post-Auth-Type Reject
+- entering group REJECT {...}
++[ldap] returns noop
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 80 to 10.1.1.1 port 47567
        Filter-Id = "Students"
        EAP-Message = 0x04050004
        Message-Authenticator = 0x00000000000000000000000000000000
Waking up in 4.9 seconds.
Cleaning up request 4 ID 80 with timestamp +56
Ready to process requests.
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.freeradius.org/pipermail/freeradius-users/attachments/20101209/49556d08/attachment.html>


More information about the Freeradius-Users mailing list