"WARNING: !! EAP session for state ... did not finish!", And Other Warnings
Matthew Newton
mcn4 at leicester.ac.uk
Sat Oct 3 01:01:14 CEST 2015
On Fri, Oct 02, 2015 at 05:24:17PM -0400, Jim Seymour wrote:
> > radiusd -X | tee logfile
> >
> > then connect the laptop to the network, and then post the logfile
> > to the list? Otherwise we've got nothing really to go on.
>
> Wellll... Okay. It's gigantic, tho. Included below.
Nope, that's fine.
> rad_recv: Access-Request packet from host 172.24.0.48 port 1509, id=0, length=203
> EAP-Message = 0x020000140177696e303035345c6a656666726579
response - EAP identity win0054\jeffrey
> Sending Access-Challenge of id 0 to 172.24.0.48 port 1509
> EAP-Message = 0x010100061920
server request - asks for PEAP
> rad_recv: Access-Request packet from host 172.24.0.48 port 1509, id=1, length=340
> EAP-Message = 0x0201008b198000000081160301007c010000780301560ef3ca1db6af18753547212e86a4c29231188ea25d38e9fc506a22d24e4ded204bac48082d3304551bb3dc2591a3abb1481a4b9e1f411604b120384460512c0d0018c014c013c00ac0090035002f00380032000a00130005000401000017000a00080006001900170018000b00020100ff01000100
client initiates PEAP
> Sending Access-Challenge of id 1 to 172.24.0.48 port 1509
> EAP-Message = 0x0102040019c000000a351603010039020000350301e3d36991a480cff0a07864e77a040402f7c8ffb3fa033663de15ee5670a7e1b600c01400000dff01000100000b00040300010216030108990b000895000892000469308204653082034da003020102020900db98278c91c043a9300d06092a864886f70d01010b05003081a5310b30090603550406130255533111300f06035504080c084d6963686967616e3121301f060355040a0c1857656c64696e6720546563686e6f6c6f677920436f72702e31153013060355040b0c0c546563682e2043656e746572311d301b06035504030c14736b796e65742d6e2e777463636f72702e636f6d312a30
> EAP-Message = 0x2806092a864886f70d010901161b686f73746d61737465724077656c6474656368636f72702e636f6d301e170d3135303933303133323735335a170d3136303932393133323735335a3081c0310b30090603550406130255533111300f06035504080c084d6963686967616e3119301706035504070c104661726d696e67746f6e2048696c6c733121301f060355040a0c1857656c64696e6720546563686e6f6c6f677920436f72702e31153013060355040b0c0c546563682e2043656e746572311d301b06035504030c14736b796e65742d6e2e777463636f72702e636f6d312a302806092a864886f70d010901161b686f73746d61737465724077
> EAP-Message = 0x656c6474656368636f72702e636f6d30820122300d06092a864886f70d01010105000382010f003082010a0282010100d2d1c7948966ed1341d267fc4f9cbb7296b538e6c723798db5cf417e57e0620f717df13563fa3ee95d91c6cbd0f2919d7cc0574e3525b145ce67bd29b491b13c0521b0d0790a9e1e153f8f5120ec29c3ef45e90eac80eceb1a72e4092484908d485fa92fa5707513fd6af7f510b56d1d0faaadb9e7cd299346fefef85bc2ea77fa161428c0c5282c5c55eff7e3eea1eb2174f802bf43d03232ada75c5e05ab926885f6f67667fab1d529a55db4bb05e1b96eb29372385b57e3b3a7adf39e856aff11f754675e831d57d5fdbacc
> EAP-Message = 0x6c871053262f2b628752fb8fe5f810342b04f8a001177ebd1722fb02c1fe13ba9d97a5fbfe928d7b4e5ec19a8158f75d44d1c90203010001a37b307930090603551d1304023000302c06096086480186f842010d041f161d4f70656e53534c2047656e657261746564204365727469666963617465301d0603551d0e041604143fd748d1e67b96f55218a8d3506b1520021ead6f301f0603551d230418301680143edcdf7a0e78b6c903868bf018eb6df83782ab9d300d06092a864886f70d01010b05000382010100499ce5c07f4f002837484b1de16566030fd0a519c6f66b6600ddecacbb55c50be98fc448739e30aef582ac786a65a70b38f0a53c
> EAP-Message = 0x205bb219d9d0950173a6e052
> State = 0x98bd762099bf6f3a092a404097a6cf8c
server sends cert part 1
> rad_recv: Access-Request packet from host 172.24.0.48 port 1509, id=2, length=207
> EAP-Message = 0x020200061900
client ack
> Sending Access-Challenge of id 2 to 172.24.0.48 port 1509
> EAP-Message = 0x010303fc1940b6da580861b855560215e1bcddc7cf7827141faabad978a814118c0396af66bb9de3c68f723e7daa398182692569baf4e2286c6ce5036cfc997577ecebc2727ff1ecbf4f7310651cf9ea2752d40b0ffa8f3d93d4e344fede5db5104358bd0361b15d3a673789d36d86caa0800071c88c6f149459efd07b25be0dd75ca2b2aa276c22bd6c8f7481af26b84dda57b527c3ed8889a96b232aba9105d1750cfd3fcf97c1ee8a9339d19ab87264461497c80c8adf4010e1a03fe4048cd611b4fdb0330004233082041f30820307a003020102020900db98278c91c043a8300d06092a864886f70d01010b05003081a5310b3009060355040613
> EAP-Message = 0x0255533111300f06035504080c084d6963686967616e3121301f060355040a0c1857656c64696e6720546563686e6f6c6f677920436f72702e31153013060355040b0c0c546563682e2043656e746572311d301b06035504030c14736b796e65742d6e2e777463636f72702e636f6d312a302806092a864886f70d010901161b686f73746d61737465724077656c6474656368636f72702e636f6d301e170d3135303933303133323732315a170d3230303932383133323732315a3081a5310b30090603550406130255533111300f06035504080c084d6963686967616e3121301f060355040a0c1857656c64696e6720546563686e6f6c6f67792043
> EAP-Message = 0x6f72702e31153013060355040b0c0c546563682e2043656e746572311d301b06035504030c14736b796e65742d6e2e777463636f72702e636f6d312a302806092a864886f70d010901161b686f73746d61737465724077656c6474656368636f72702e636f6d30820122300d06092a864886f70d01010105000382010f003082010a0282010100c944842f637fef492dcb8b64ea061235ea559291b19a5ae5edc0ed30743c49f613d8e02b4f1c550e2a10a2949470e97d1bfa77fd2d72cf5705e203ab73384d91885043238a0a28aba3da3852a88569281c07f2625df0c9fc44bd7e2b74e1bd17b30e13a34ce06642eb8ea20eab0ac013b1e0295106d8
> EAP-Message = 0xdebfec3c001b3f97c99db881f0bc8175bc2f8a06a57dd173f43d092f406832fa4d379b4e3d139fcd2b17ffc3d462ee2d1bb7f4170af942c0d04e00a7d9735378bca2b39c5442683a6a0311a8c0c24d4782e969362ea68480960546166f7683dde3e32638fb36b04b302198f997e2afb50880b63ffdff863a7812b4e9c0cc7ccda4424c344f3f7f180bf70203010001a350304e301d0603551d0e041604143edcdf7a0e78b6c903868bf018eb6df83782ab9d301f0603551d230418301680143edcdf7a0e78b6c903868bf018eb6df83782ab9d300c0603551d13040530030101ff300d06092a864886f70d01010b0500038201010059c531727c748cb0
> EAP-Message = 0xa73687495c5cba6d
> State = 0x98bd76209abe6f3a092a404097a6cf8c
server sends cert part 2
> rad_recv: Access-Request packet from host 172.24.0.48 port 1509, id=3, length=207
> EAP-Message = 0x020300061900
client ack
> Sending Access-Challenge of id 3 to 172.24.0.48 port 1509
> EAP-Message = 0x0104024f1900e7d5270f188a0f21028c17db0c4d3a4838d86a59ff3eec796b43f0c60983ea0d40fd86610f59e6575677f9700434ca9aaea69f8849614008fd93ade3852afb2eef925278f3b28c615233ec17b84f3299944dcb6c776ef66cbb07c8a503ca018747ef169ce512d4b2f1a102b7f941d62239c3cd554545cc8a0662221db9c71caa130d342979bbe0b1ae33d10737740e92a776c525965e97d1f9ab305c7226f8f26c03063af5d76628eba9e851ae0f807182cd582cf834384de1df8b513aff09dcb8409ca58449b5c987a8f574139352b15b5b73e56114eac58602765d28ea98181c344c48f313d5a29a2f2accfb06d4b7160301014b0c00
> EAP-Message = 0x0147030017410458221b4f9563c367cd6345bd1983dd5a0a1d2d9c0c3f3a688675135a2a3dd158eb7ce2a321395da49acebf6d58bb7bc638b6ac01ea1f1dacbbb3f1891effafa701002df95433bd6b5e8b9e54b46658f83af70565a8bacc68904416919cc68c38c00bb8d03e56d7b9825bcbc107f05a8505c371fe58f730e929a777ac59b5f8d8c3ffdb6c1cd8f18f3964224390d311b9d52e76817b0c33d34c42756e9726eb789ecc12975de7b3754bb382aee43ed892b392da09e278fd7b1c1b2a087fdd4ff4a3a9b68abec44550f6fbbedfc24c43eb889c23f921690d5005c4c0d6f09532e9c5fd19bd9f0fad6ec02b28579cdb08e69345d4cabd93
> EAP-Message = 0x988e23bbfd7da569b3228fce00255d14115514e296d1cdcabfc471f6a93865e4727403723468dd50253baec481920b34f9bbd4b31d488db221f224bb73a98de198ce3c3bbaea63a73de0640d16030100040e000000
> State = 0x98bd76209bb96f3a092a404097a6cf8c
server sends last part of cert
> rad_recv: Access-Request packet from host 172.24.0.48 port 1509, id=4, length=207
> EAP-Message = 0x020400061900
client sends ack
> Sending Access-Challenge of id 4 to 172.24.0.48 port 1509
> EAP-Message = 0x010500061900
> State = 0x98bd76209cb86f3a092a404097a6cf8c
server sends ack.
Note the state here.
> rad_recv: Access-Request packet from host 172.24.0.48 port 1510, id=0, length=203
> EAP-Message = 0x020000140177696e303035345c6a656666726579
client sends identity again - win0054\jeffrey
huh? The client didn't like something, bombed out and
started again.
> Sending Access-Challenge of id 0 to 172.24.0.48 port 1510
> EAP-Message = 0x010100061920
> State = 0x4465ca6b4464d3fe9d648e243ee182ad
server requests peap
> rad_recv: Access-Request packet from host 172.24.0.48 port 1510, id=1, length=308
> EAP-Message = 0x0201006b198000000061160301005c010000580301560ef3ccbf5284b3d32a2f4774af9d62f43b2ee8527a8caeff6653df745e5cef000018c014c013c00ac0090035002f00380032000a00130005000401000017000a00080006001900170018000b00020100ff01000100
client starts PEAP again
> Sending Access-Challenge of id 1 to 172.24.0.48 port 1510
> EAP-Message = 0x0102040019c000000a351603010039020000350301563f8767bca18f9ef80d326eb862a320de9154c43e762c9317971aa689858f3600c01400000dff01000100000b00040300010216030108990b000895000892000469308204653082034da003020102020900db98278c91c043a9300d06092a864886f70d01010b05003081a5310b30090603550406130255533111300f06035504080c084d6963686967616e3121301f060355040a0c1857656c64696e6720546563686e6f6c6f677920436f72702e31153013060355040b0c0c546563682e2043656e746572311d301b06035504030c14736b796e65742d6e2e777463636f72702e636f6d312a30
> EAP-Message = 0x2806092a864886f70d010901161b686f73746d61737465724077656c6474656368636f72702e636f6d301e170d3135303933303133323735335a170d3136303932393133323735335a3081c0310b30090603550406130255533111300f06035504080c084d6963686967616e3119301706035504070c104661726d696e67746f6e2048696c6c733121301f060355040a0c1857656c64696e6720546563686e6f6c6f677920436f72702e31153013060355040b0c0c546563682e2043656e746572311d301b06035504030c14736b796e65742d6e2e777463636f72702e636f6d312a302806092a864886f70d010901161b686f73746d61737465724077
> EAP-Message = 0x656c6474656368636f72702e636f6d30820122300d06092a864886f70d01010105000382010f003082010a0282010100d2d1c7948966ed1341d267fc4f9cbb7296b538e6c723798db5cf417e57e0620f717df13563fa3ee95d91c6cbd0f2919d7cc0574e3525b145ce67bd29b491b13c0521b0d0790a9e1e153f8f5120ec29c3ef45e90eac80eceb1a72e4092484908d485fa92fa5707513fd6af7f510b56d1d0faaadb9e7cd299346fefef85bc2ea77fa161428c0c5282c5c55eff7e3eea1eb2174f802bf43d03232ada75c5e05ab926885f6f67667fab1d529a55db4bb05e1b96eb29372385b57e3b3a7adf39e856aff11f754675e831d57d5fdbacc
> EAP-Message = 0x6c871053262f2b628752fb8fe5f810342b04f8a001177ebd1722fb02c1fe13ba9d97a5fbfe928d7b4e5ec19a8158f75d44d1c90203010001a37b307930090603551d1304023000302c06096086480186f842010d041f161d4f70656e53534c2047656e657261746564204365727469666963617465301d0603551d0e041604143fd748d1e67b96f55218a8d3506b1520021ead6f301f0603551d230418301680143edcdf7a0e78b6c903868bf018eb6df83782ab9d300d06092a864886f70d01010b05000382010100499ce5c07f4f002837484b1de16566030fd0a519c6f66b6600ddecacbb55c50be98fc448739e30aef582ac786a65a70b38f0a53c
> EAP-Message = 0x205bb219d9d0950173a6e052
server sends cert part 1
> rad_recv: Access-Request packet from host 172.24.0.48 port 1510, id=2, length=207
> EAP-Message = 0x020200061900
client ack
> Sending Access-Challenge of id 2 to 172.24.0.48 port 1510
> EAP-Message = 0x010303fc1940b6da580861b855560215e1bcddc7cf7827141faabad978a814118c0396af66bb9de3c68f723e7daa398182692569baf4e2286c6ce5036cfc997577ecebc2727ff1ecbf4f7310651cf9ea2752d40b0ffa8f3d93d4e344fede5db5104358bd0361b15d3a673789d36d86caa0800071c88c6f149459efd07b25be0dd75ca2b2aa276c22bd6c8f7481af26b84dda57b527c3ed8889a96b232aba9105d1750cfd3fcf97c1ee8a9339d19ab87264461497c80c8adf4010e1a03fe4048cd611b4fdb0330004233082041f30820307a003020102020900db98278c91c043a8300d06092a864886f70d01010b05003081a5310b3009060355040613
> EAP-Message = 0x0255533111300f06035504080c084d6963686967616e3121301f060355040a0c1857656c64696e6720546563686e6f6c6f677920436f72702e31153013060355040b0c0c546563682e2043656e746572311d301b06035504030c14736b796e65742d6e2e777463636f72702e636f6d312a302806092a864886f70d010901161b686f73746d61737465724077656c6474656368636f72702e636f6d301e170d3135303933303133323732315a170d3230303932383133323732315a3081a5310b30090603550406130255533111300f06035504080c084d6963686967616e3121301f060355040a0c1857656c64696e6720546563686e6f6c6f67792043
> EAP-Message = 0x6f72702e31153013060355040b0c0c546563682e2043656e746572311d301b06035504030c14736b796e65742d6e2e777463636f72702e636f6d312a302806092a864886f70d010901161b686f73746d61737465724077656c6474656368636f72702e636f6d30820122300d06092a864886f70d01010105000382010f003082010a0282010100c944842f637fef492dcb8b64ea061235ea559291b19a5ae5edc0ed30743c49f613d8e02b4f1c550e2a10a2949470e97d1bfa77fd2d72cf5705e203ab73384d91885043238a0a28aba3da3852a88569281c07f2625df0c9fc44bd7e2b74e1bd17b30e13a34ce06642eb8ea20eab0ac013b1e0295106d8
> EAP-Message = 0xdebfec3c001b3f97c99db881f0bc8175bc2f8a06a57dd173f43d092f406832fa4d379b4e3d139fcd2b17ffc3d462ee2d1bb7f4170af942c0d04e00a7d9735378bca2b39c5442683a6a0311a8c0c24d4782e969362ea68480960546166f7683dde3e32638fb36b04b302198f997e2afb50880b63ffdff863a7812b4e9c0cc7ccda4424c344f3f7f180bf70203010001a350304e301d0603551d0e041604143edcdf7a0e78b6c903868bf018eb6df83782ab9d301f0603551d230418301680143edcdf7a0e78b6c903868bf018eb6df83782ab9d300c0603551d13040530030101ff300d06092a864886f70d01010b0500038201010059c531727c748cb0
> EAP-Message = 0xa73687495c5cba6d
server certs part 2
> rad_recv: Access-Request packet from host 172.24.0.48 port 1510, id=3, length=207
> EAP-Message = 0x020300061900
client ack
> Sending Access-Challenge of id 3 to 172.24.0.48 port 1510
> EAP-Message = 0x0104024f1900e7d5270f188a0f21028c17db0c4d3a4838d86a59ff3eec796b43f0c60983ea0d40fd86610f59e6575677f9700434ca9aaea69f8849614008fd93ade3852afb2eef925278f3b28c615233ec17b84f3299944dcb6c776ef66cbb07c8a503ca018747ef169ce512d4b2f1a102b7f941d62239c3cd554545cc8a0662221db9c71caa130d342979bbe0b1ae33d10737740e92a776c525965e97d1f9ab305c7226f8f26c03063af5d76628eba9e851ae0f807182cd582cf834384de1df8b513aff09dcb8409ca58449b5c987a8f574139352b15b5b73e56114eac58602765d28ea98181c344c48f313d5a29a2f2accfb06d4b7160301014b0c00
> EAP-Message = 0x01470300174104f94f27db84c936ece3f8f2dabd1578d95d6ac7a27dfb6daa83d62030d7be1f8298f1889a729c7ed1475895e8f796516031e5bb67c5779570fe2e3baa4fc59f980100656917d6493b86f841676412f995ab7e1ba7c1e28e39d94c08325c836b0887772396b6b04f6db1bcbc09f143184d3d37677a484de33a58e0b182788527dede27c5345dba9bd4e06dd487cb32c55e95efeab1cf8b4b5726b5950c473d5264c03ec379147429d3492e4695a1153ba005598749f4a9f13e3847148f3455cffc4121180cdc839bc84dccf2758f4d624583bf051e94fcaecded9834a0e7c632087051a0cada0de572368894b07c019e3e85a379e8df26
> EAP-Message = 0x3c7a29973798e12add22ade92b3511a131fb4d81bfcdec1d7106d6c70b89fed598f1aca96b1ce9d45de544b8f2d96c2bde80f76ae69041e752e6ddbfcbafca70df67258cdeff72cc52f1958616030100040e000000
server certs part 3
> rad_recv: Access-Request packet from host 172.24.0.48 port 1510, id=4, length=345
> EAP-Message = 0x0204009019800000008616030100461000004241043c809efc0e0a2ca176b2606111d62bf84fc511208a5bf64b3017688baf469126994847f9f55b6a4a9a14f69a5cc2d9093ca45977068034173e49aa8c6567ef231403010001011603010030cfd781c88abc2f1f2308318db52c884dc33bb5034282e0be3ae40b6265ee2d415484e772c9889a03bfd6d113e8b7b925
client contines PEAP...
> Found Auth-Type = EAP
> # Executing group from file /etc/freeradius/sites-enabled/default
> +group authenticate {
> [eap] Request found, released from the list
> [eap] EAP/peap
> [eap] processing type peap
> [peap] processing EAP-TLS
> TLS Length 134
> [peap] Length Included
> [peap] eaptls_verify returned 11
> [peap] <<< TLS 1.0 Handshake [length 0046], ClientKeyExchange
> [peap] TLS_accept: SSLv3 read client key exchange A
> [peap] <<< TLS 1.0 ChangeCipherSpec [length 0001]
> [peap] <<< TLS 1.0 Handshake [length 0010], Finished
> [peap] TLS_accept: SSLv3 read finished A
> [peap] >>> TLS 1.0 ChangeCipherSpec [length 0001]
> [peap] TLS_accept: SSLv3 write change cipher spec A
> [peap] >>> TLS 1.0 Handshake [length 0010], Finished
> [peap] TLS_accept: SSLv3 write finished A
> [peap] TLS_accept: SSLv3 flush data
> [peap] (other): SSL negotiation finished successfully
> SSL Connection Established
gotcha.
> Sending Access-Challenge of id 4 to 172.24.0.48 port 1510
> EAP-Message = 0x010500411900140301000101160301003013153c9bcbbbc61fdf54f31d9dc1f6e0f0688aed91c84831ea12d943c445d4bc36982989b0a1c12ffff77e06438851c7
...
> rad_recv: Access-Request packet from host 172.24.0.48 port 1510, id=6, length=260
> EAP-Message = 0x0206003b19001703010030ace4d439a4ad129c9a846d74d6695ccaea39e77e2c524cf5065c69ae97d02d1c7dc9ec9c5a4e7d530ef19a7485a6d6f0
into the inner tunnel
> [peap] processing EAP-TLS
> [peap] eaptls_verify returned 7
> [peap] Done initial handshake
> [peap] eaptls_process returned 7
> [peap] EAPTLS_OK
> [peap] Session established. Decoding tunneled attributes.
> [peap] Peap state WAITING FOR INNER IDENTITY
> [peap] Identity - win0054\jeffrey
> [peap] Got inner identity 'win0054\jeffrey'
> [peap] Setting default EAP type for tunneled EAP session.
> [peap] Got tunneled request
> EAP-Message = 0x020600140177696e303035345c6a656666726579
> server {
> [peap] Setting User-Name to win0054\jeffrey
> Sending tunneled request
> EAP-Message = 0x020600140177696e303035345c6a656666726579
inner tunnel identity win0054\jeffrey
and we're away.... completes with
> Sending Access-Accept of id 9 to 172.24.0.48 port 1510
> MS-MPPE-Recv-Key = 0xb6366ecd1300654a450cf0f52f17764ceef21afb49657ae5569ac80e7ac85529
> MS-MPPE-Send-Key = 0xfe041f1c30415092e2a826a51a0ff7eff3d0fceac33d78f95f08a36ad310fec0
> EAP-Message = 0x03090004
> Message-Authenticator = 0x00000000000000000000000000000000
> User-Name = "win0054\\jeffrey"
So this is why you get on. The *second* auth request succeeds.
> Cleaning up request 4 ID 4 with timestamp +32
> WARNING: !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
> WARNING: !! EAP session for state 0x98bd76209cb86f3a did not finish!
> WARNING: !! Please read http://wiki.freeradius.org/guide/Certificate_Compatibility
> WARNING: !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
Note state 0x98bd76209cb86f3a above - this is the *first* request.
So the question is... why did the client reject the first auth,
but then immediately re-try and accept the certificate the second
time.
I'd look at the client and see if you can get logs off it (hard on
Windows I know, have to enable eap tracing, it's a right pig to
read compared to -X on the server side...) to see why it rejected
the first time - if you can get anything from it. I'm assuming the
TLS Server OID is in the cert because it works the second time,
but worth checking anyway.
Check the certificate chain to make sure that it all verifies OK
and has nothing that looks odd about it. Has the client got the
root CA installed properly?
Try removing the entire client config and setting it up again.
I've seen Win7 get itself confused and removing and adding the
wireless settings has sorted it.
Matthew
--
Matthew Newton, Ph.D. <mcn4 at le.ac.uk>
Systems Specialist, Infrastructure Services,
I.T. Services, University of Leicester, Leicester LE1 7RH, United Kingdom
For IT help contact helpdesk extn. 2253, <ithelp at le.ac.uk>
More information about the Freeradius-Users
mailing list