Not going past "Sending Access-Challenge"

2 Sep 2005

      Supplicant: Windows XP SP2 setup for PEAP authentication
WAP: D-Link DI-524
Server: SuSe LINUX 9.3, freeradius-1.0.2-5.5

I'm trying to setup RADIUS/WPA authentication using PEAP as described in -
http://www.ibiblio.org/pub/Linux/docs/HOWTO/8021X-HOWTO - but I never seem to
get past the "Sending Access-Challenge" after I enter my username and password
on the client.  User is simply an entry in the users file with a clear text
password.  I've gone over the config several times, but nothing jumps out at me
as an error message.

rad_recv: Access-Request packet from host 10.221.1.11:1541, id=212, length=133
        User-Name = "awilliam"
        NAS-IP-Address = 10.221.1.11
        NAS-Port = 0
        Called-Station-Id = "00-0F-3D-43-6A-3C"
        Calling-Station-Id = "00-14-A5-30-C8-EB"
        NAS-Identifier = "wap001"
        Framed-MTU = 1380
        NAS-Port-Type = Wireless-802.11
        EAP-Message = 0x0201000d016177696c6c69616d
        Message-Authenticator = 0xb73dc28ab29c185fa08d6e9a89c4a7b6
  Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 12
  modcall[authorize]: module "preprocess" returns ok for request 12
  modcall[authorize]: module "mschap" returns noop for request 12
    rlm_realm: No '@' in User-Name = "awilliam", looking up realm NULL
    rlm_realm: No such realm "NULL"
  modcall[authorize]: module "suffix" returns noop for request 12
  rlm_eap: EAP packet type response id 1 length 13
  rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
  modcall[authorize]: module "eap" returns updated for request 12
    users: Matched entry awilliam at line 47
  modcall[authorize]: module "files" returns ok for request 12
modcall: group authorize returns updated for request 12
  rad_check_password:  Found Auth-Type EAP
auth: type "EAP"
  Processing the authenticate section of radiusd.conf
modcall: entering group authenticate for request 12
  rlm_eap: EAP Identity
  rlm_eap: processing type tls
  rlm_eap_tls: Initiate
  rlm_eap_tls: Start returned 1
  modcall[authenticate]: module "eap" returns handled for request 12
modcall: group authenticate returns handled for request 12
Sending Access-Challenge of id 212 to 10.221.1.11:1541
        Reply-Message = "EAPTEST Hello, %u"
        EAP-Message = 0x010200061920
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0xb58f01c20fe2bd7f76cb3c17a39ce5bc
Finished request 12
Going to the next request

--- Walking the entire request list ---
Waking up in 6 seconds...
rad_recv: Access-Request packet from host 10.221.1.11:1541, id=213, length=218
        User-Name = "awilliam"
        NAS-IP-Address = 10.221.1.11
        NAS-Port = 0
        Called-Station-Id = "00-0F-3D-43-6A-3C"
        Calling-Station-Id = "00-14-A5-30-C8-EB"
        NAS-Identifier = "wap001"
        Framed-MTU = 1380
        NAS-Port-Type = Wireless-802.11
        EAP-Message =
0x0202005019800000004616030100410100003d030143188e25fe428c058fdc71c40dc5fd45d16272d128cfb38a046d8395cdb9495400001600040005000a000900640062000300060013001200630100
        State = 0xb58f01c20fe2bd7f76cb3c17a39ce5bc
        Message-Authenticator = 0x56a49625573ffd294ec9fd177e77ab21
  Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 13
  modcall[authorize]: module "preprocess" returns ok for request 13
  modcall[authorize]: module "mschap" returns noop for request 13
    rlm_realm: No '@' in User-Name = "awilliam", looking up realm NULL
    rlm_realm: No such realm "NULL"
  modcall[authorize]: module "suffix" returns noop for request 13
  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 13
    users: Matched entry awilliam at line 47
  modcall[authorize]: module "files" returns ok for request 13
modcall: group authorize returns updated for request 13
  rad_check_password:  Found Auth-Type EAP
auth: type "EAP"
  Processing the authenticate section of radiusd.conf
modcall: entering group authenticate for request 13
  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 0e04], 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 13
modcall: group authenticate returns handled for request 13
Sending Access-Challenge of id 213 to 10.221.1.11:1541
        Reply-Message = "EAPTEST Hello, %u"
        EAP-Message =
0x0103040a19c000000e61160301004a02000046030143188e264d363afca2208f96579a37c9b6ce24b29f373fd89c6aeb23beabbe6a20ae8f6882a1ff9b2d6a30857db72b3e9835f11bfac5c4cff0075b8b80b7547a340004001603010e040b000e00000dfd000666308206623082044aa00302010202010a300d06092a864886f70d01010505003081b4310b30090603550406130255533111300f060355040813084d4963686967616e311530130603550407130c4772616e6420526170696473311c301a060355040a13134d6f727269736f6e20496e647573747269657331153013060355040b130c4349532f495420446570742e311c301a060355
        EAP-Message =
0x040313134d6f727269736f6e20496e64757374726965733128302606092a864886f70d01090116196369737374616666406d6f727269736f6e2d696e642e636f6d301e170d3035303930323133353635355a170d3133313131393133353635355a308189310b30090603550406130255533111300f060355040813084d4963686967616e311530130603550407130c4772616e6420526170696473311c301a060355040a13134d6f727269736f6e20496e6475737472696573310c300a060355040b1303434953312430220603550403131b6669726577616c6c2e6d6f727269736f6e2e69736572762e6e657430820122300d06092a864886f70d0101
        EAP-Message =
0x0105000382010f003082010a0282010100ce8fd89320d316512c62ac097b844ee08bff03850e8faa27b796fb5e26a7d207bc7a248acf8712fff6dfe685356bc39e621ce3fdef03203d96cdc4b29eb4fa95e19d733551d09839f30116495479f81d67d9f28d01f0fa02ff2dc23a882f141164fb1d773663b1b6b066f4a1cf180459aa0b148a0a3340b7dc21760a72e945b53b576e10ad5657941ae8d2ad467424215c350f308179fd3b30203f11746e34eb13e741d8338e4c112e3207281b8df760912ff2fafee5d9de4826fe5c5d8ae94341f5b75b1fcee56882304a4cf9b106750ce8ab8e42ddb1dbe83ecfb43be491f0e9f84d4d022882219c69ec47
        EAP-Message =
0x0e9218ffa316e221cbad2513d02acee4830995d10203010001a38201a6308201a230090603551d1304023000301106096086480186f8420101040403020640302b06096086480186f842010d041e161c54696e7943412047656e657261746564204365727469666963617465301d0603551d0e0416041492f5614a787c1daefd9794ebe6446f0439e6cabf3081e90603551d230481e13081de80145db58bfba4972ffa5cdee6f4660cab60b9a55cf0a181baa481b73081b4310b30090603550406130255533111300f060355040813084d4963686967616e311530130603550407130c4772616e6420526170696473311c301a060355040a13134d6f72
        EAP-Message = 0x7269736f6e20496e6475737472696573311530130603
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x713c730655eee3a9a367d9d401f7a00a
Finished request 13

Going to the next request
Waking up in 6 seconds...
rad_recv: Access-Request packet from host 10.221.1.11:1541, id=214, length=144
        User-Name = "awilliam"
        NAS-IP-Address = 10.221.1.11
        NAS-Port = 0
        Called-Station-Id = "00-0F-3D-43-6A-3C"
        Calling-Station-Id = "00-14-A5-30-C8-EB"
        NAS-Identifier = "wap001"
        Framed-MTU = 1380
        NAS-Port-Type = Wireless-802.11
        EAP-Message = 0x020300061900
        State = 0x713c730655eee3a9a367d9d401f7a00a
        Message-Authenticator = 0x25adbdf94a084a0520c22a785b189b77
  Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 14
  modcall[authorize]: module "preprocess" returns ok for request 14
  modcall[authorize]: module "mschap" returns noop for request 14
    rlm_realm: No '@' in User-Name = "awilliam", looking up realm NULL
    rlm_realm: No such realm "NULL"
  modcall[authorize]: module "suffix" returns noop for request 14
  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 14
    users: Matched entry awilliam at line 47
  modcall[authorize]: module "files" returns ok for request 14
modcall: group authorize returns updated for request 14
  rad_check_password:  Found Auth-Type EAP
auth: type "EAP"
  Processing the authenticate section of radiusd.conf
modcall: entering group authenticate for request 14
  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 14
modcall: group authenticate returns handled for request 14
Sending Access-Challenge of id 214 to 10.221.1.11:1541
        Reply-Message = "EAPTEST Hello, %u"
        EAP-Message =
0x01040406194055040b130c4349532f495420446570742e311c301a060355040313134d6f727269736f6e20496e64757374726965733128302606092a864886f70d01090116196369737374616666406d6f727269736f6e2d696e642e636f6d820900cc644cbcb3c8952c30240603551d12041d301b81196369737374616666406d6f727269736f6e2d696e642e636f6d30240603551d11041d301b81196369737374616666406d6f727269736f6e2d696e642e636f6d300d06092a864886f70d0101050500038202010031273c15a3d38c0dc668d84db88aa9e487ffeb0cc626227ca9f460468f52dbeeb92496d0f091df082071145f94fce9b32a199a
        EAP-Message =
0x33efb30f3964f1fc2329c7a178e4d69312ccca3aa835cd917a0651cf8c13796b479fd2d39df0e8043dc044ac8e426dbff3e0ba5d58ce77962962b33e0ca262c8ff647a7c808ef29a96794bf1dfeefd3b52fef2a4e7be9f3ccff3b6ecb36624dd4c480f9abe0d3437a8f0f43d6babb055d5c0092a37fd935066f8a9aa3e3244cfb33e1fb987eb369730ca096e1d95cd93a330d9b7dad4f4fb3264be42b5dd96772b2f7573e5f3e26e19b4e73c352beb094d0869c5f14fc70a08745ac82ea8749b80fd8606dea216d53ea578d52010cea78ca9b75faedadad75059c73f967e4585983468ed194c7977262d0b8af33d26197adfefae4ed420f5108fd3670f
        EAP-Message =
0x7bc7d669fc9bea43cfa651ffd9521e536f167b008cdcbf485678af25eb5f6e29a51e7b3d38f7c1234f6a50319d02102c0d98ac871c1e224839acb387900b391220507039eebfb7d03c6a3edae52739fbecd1db8468ee3225f0117710d7e7e0a25db4a3152d38b3a5dc0bdacba7bb51a9087826c0ea6cef2fdddb5f4674cd9d792f0aa25ebab4d4a6e96fad7257ccb3038c4bc4537a7b09853e72dc0da70e80105e378da9ede0fb0d03e4e5fc4beae256099be7871821ae422a8376ae6b05f1ed93d5db1cdbf06b3a78c956bd2a6aa59f0007913082078d30820575a003020102020900cc644cbcb3c8952c300d06092a864886f70d01010505003081b4
        EAP-Message =
0x310b30090603550406130255533111300f060355040813084d4963686967616e311530130603550407130c4772616e6420526170696473311c301a060355040a13134d6f727269736f6e20496e647573747269657331153013060355040b130c4349532f495420446570742e311c301a060355040313134d6f727269736f6e20496e64757374726965733128302606092a864886f70d01090116196369737374616666406d6f727269736f6e2d696e642e636f6d301e170d3035303732353133343633325a170d3135303732333133343633325a3081b4310b30090603550406130255533111300f060355040813084d4963686967616e311530130603
        EAP-Message = 0x550407130c4772616e642052617069647331
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x2c41f0b34b5f2fd3cf8982b4f9526a6d
Finished request 14

Going to the next request
--- Walking the entire request list ---
Waking up in 5 seconds...
rad_recv: Access-Request packet from host 10.221.1.11:1541, id=215, length=144
        User-Name = "awilliam"
        NAS-IP-Address = 10.221.1.11
        NAS-Port = 0
        Called-Station-Id = "00-0F-3D-43-6A-3C"
        Calling-Station-Id = "00-14-A5-30-C8-EB"
        NAS-Identifier = "wap001"
        Framed-MTU = 1380
        NAS-Port-Type = Wireless-802.11
        EAP-Message = 0x020400061900
        State = 0x2c41f0b34b5f2fd3cf8982b4f9526a6d
        Message-Authenticator = 0x5de7fc17ae10cb4f2bb0d89efb4157c4
  Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 15
  modcall[authorize]: module "preprocess" returns ok for request 15
  modcall[authorize]: module "mschap" returns noop for request 15
    rlm_realm: No '@' in User-Name = "awilliam", looking up realm NULL
    rlm_realm: No such realm "NULL"
  modcall[authorize]: module "suffix" returns noop for request 15
  rlm_eap: EAP packet type response id 4 length 6
  rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
  modcall[authorize]: module "eap" returns updated for request 15
    users: Matched entry awilliam at line 47
  modcall[authorize]: module "files" returns ok for request 15
modcall: group authorize returns updated for request 15
  rad_check_password:  Found Auth-Type EAP
auth: type "EAP"
  Processing the authenticate section of radiusd.conf
modcall: entering group authenticate for request 15
  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 15
modcall: group authenticate returns handled for request 15
Sending Access-Challenge of id 215 to 10.221.1.11:1541
        Reply-Message = "EAPTEST Hello, %u"
        EAP-Message =
0x0105040619401c301a060355040a13134d6f727269736f6e20496e647573747269657331153013060355040b130c4349532f495420446570742e311c301a060355040313134d6f727269736f6e20496e64757374726965733128302606092a864886f70d01090116196369737374616666406d6f727269736f6e2d696e642e636f6d30820222300d06092a864886f70d01010105000382020f003082020a0282020100a46610d5227c9609b10fdcf860d7a358d9d6b38295c4584e0cfaee3bfe5289828041bd9d9be0b778836aa357a194357cbd0801c80a48623b47c1b762eb0a4f352de04b33d18364f36f5fe35a5c5821319a23f47be10edc53fe78
        EAP-Message =
0x050992c23ca2da47e70fd6078c4f8276b2d8960deb3cae6b201b9c0375bd29a6aaca61b53b75e77b9027f6d7b70ee6dd50976f4b8419da3b33c225dfff9f5e0d0722dd0d21bdd75b7351ef1d04c4bc2bb0a17f00c280c4813b6a7ffd44c7f1c0790728d817e978e6bca0fd38cf025175373126e012535fda6dd550a71bb3699b0d5904b0f584db6d85b29b23daccdccb4af4299de370fb634787d2ce9f7bf2c75f8fd5d604c9ee51fd8890724b600094cf0f0096ee3d2c78fef95241e1f909f711d4aee53b812207b93539d362197f8afab367de0107068dc650e6facdfc439c2ad8055d5155668bea5a956a75f78058cb2b609103d2473c8062d1d37b
        EAP-Message =
0xc9b03ac11e2963775bd7fdde2d57b164811eebc753d0d8612b4a949c9d62c8b648a3c46c90f56f8af2e8bad7887c53f43bd4cff4a2cb9d212d4e4d8171a0856834ee08803c13a73f79975b8923ec2ba24bec674deb725b3bccfcb65d722ec382fc3bd56a35e956eee601eb6b959c78aa83cc6a220fd7701d7775f93e967aa6b4a0a11c5ca1454d68a7df81a0482fb8843fbf49957e2915fbed9d1ff9b79c780d4c003b7638e9416c5f0203010001a382019e3082019a301d0603551d0e041604145db58bfba4972ffa5cdee6f4660cab60b9a55cf03081e90603551d230481e13081de80145db58bfba4972ffa5cdee6f4660cab60b9a55cf0a181baa4
        EAP-Message =
0x81b73081b4310b30090603550406130255533111300f060355040813084d4963686967616e311530130603550407130c4772616e6420526170696473311c301a060355040a13134d6f727269736f6e20496e647573747269657331153013060355040b130c4349532f495420446570742e311c301a060355040313134d6f727269736f6e20496e64757374726965733128302606092a864886f70d01090116196369737374616666406d6f727269736f6e2d696e642e636f6d820900cc644cbcb3c8952c300f0603551d130101ff040530030101ff301106096086480186f842010104040302010630090603551d1204023000302b06096086480186f8
        EAP-Message = 0x42010d041e161c54696e7943412047656e65
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x7c11d7daa209d16e0b0d0a99ef46790d
Finished request 15
Going to the next request

--- Walking the entire request list ---
Waking up in 3 seconds...
rad_recv: Access-Request packet from host 10.221.1.11:1541, id=216, length=144
        User-Name = "awilliam"
        NAS-IP-Address = 10.221.1.11
        NAS-Port = 0
        Called-Station-Id = "00-0F-3D-43-6A-3C"
        Calling-Station-Id = "00-14-A5-30-C8-EB"
        NAS-Identifier = "wap001"
        Framed-MTU = 1380
        NAS-Port-Type = Wireless-802.11
        EAP-Message = 0x020500061900
        State = 0x7c11d7daa209d16e0b0d0a99ef46790d
        Message-Authenticator = 0x0055dadddf470d4c453a2ba1316066aa
  Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 16
  modcall[authorize]: module "preprocess" returns ok for request 16
  modcall[authorize]: module "mschap" returns noop for request 16
    rlm_realm: No '@' in User-Name = "awilliam", looking up realm NULL
    rlm_realm: No such realm "NULL"
  modcall[authorize]: module "suffix" returns noop for request 16
  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 16
    users: Matched entry awilliam at line 47
  modcall[authorize]: module "files" returns ok for request 16
modcall: group authorize returns updated for request 16
  rad_check_password:  Found Auth-Type EAP
auth: type "EAP"
  Processing the authenticate section of radiusd.conf
modcall: entering group authenticate for request 16
  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 16
modcall: group authenticate returns handled for request 16
Sending Access-Challenge of id 216 to 10.221.1.11:1541
        Reply-Message = "EAPTEST Hello, %u"
        EAP-Message =
0x010602671900726174656420436572746966696361746530240603551d11041d301b81196369737374616666406d6f727269736f6e2d696e642e636f6d300b0603551d0f040403020106300d06092a864886f70d010105050003820201000b6a6c2a1faf1a32bbcb745e1d294ca5546856bfa6b6cd8be68e1950c44438e6c87ebab8dd64cd80e468ec44ff14d8c44d5f34eb5019fdfffb81cf8bc449808658175ffece877964ce819aa0b992664690ac087394d7742ff999c6390c27a644a8ae379643870dd7866fdae50fd090b54193c685632a47df8d8947b69bb7d757556979caa9bc96ccbe2b8d0fff84771ff2268bf4313c29b2de9ff7f89fae33
        EAP-Message =
0x106b3f7e90f47962f32652000b72f2c2193aded6825094bab2d2ba521875b4e417263189cb4af381a7dee20320012afc4a0315ebdeca87e75ff2054f39c750f354b29e4f036d509d7e184899c790b49f408cb86babe8592717b1a8920aa7a9450ad97de00a0908a7f4cef9a6f5db433a2a0159e6f54124e71d8b55ce5f41d4a54970c44aa94e16b1793e80bdb3a71a018e21145acbf3b57dedf2f6021caebcf4ee79f1a1656a99ee1c3bfb9cabc6fc8590838e411cec60cfa89404f85308f4e8ce396a272c4c8ab723b7d00f59925da2e4da21bed74bce7122daf4c081b46224f1c69142a0398812bb8f8b6dffd8a2ff402810913372aab0a3a6a43581
        EAP-Message =
0x9fe4fc70e0d267463d34a655b3b21889f1425bc2987bb4710ec51cc3cea614a30c7f7dc2816edb152f66ffe1b18f8d8bc51fdae1967296fb708d689578c07c386f34fafc9d8ba4c2e910914d305c21a09ec6de511cf9cc6bd8855030b1a94890d1cc969516030100040e000000
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0xa01f4a2ae94b3bff2ed31aef024624b6
Finished request 16

-- 
Adam Tauno Williams - http://www.whitemice.org