[RADIATOR] TLS Session Resumption does not work on Windows Server 2008 R2 64-bit.
Johnson, Neil M
neil-johnson at uiowa.edu
Mon May 14 17:02:52 CDT 2012
I have been testing TLS Session Resumption and found that when I moved the
RADIATOR configuration from 32-bit Windows Server 2003 R2 to 64-bit
Windows Server 2008 R2 that it stopped working. The wireless controller
reports a time-out during the 1st phase of the for way handshake.
If I restart the RADIUS server, the authentication works the first time I
connect, but then fails if I try to reconnect.
This is a sample from the log on the wireless controller:
2012-May-13 17:09:15.743769 | 00:1b:77:1f:cd:5b | Station Assign |
<AID=1> assigned to
<AP_ID=569><ESSID=UI-eduroam><BSSID=00:0c:e6:83:87:19><reason=Station
probed>
2012-May-13 17:09:15.792611 | 00:1b:77:1f:cd:5b | 802.11 State |
state change
<old=Unauthenticated><new=Authenticated><AP=00:0c:e6:06:30:ad><BSSID=00:0c:
e6:83:87:19>
2012-May-13 17:09:15.794520 | 00:1b:77:1f:cd:5b | 1X Authentication |
<EAP code=request> <EAP ID=1> <EAP type=Identity> sent
2012-May-13 17:09:15.794526 | 00:1b:77:1f:cd:5b | 802.11 State |
state change
<old=Authenticated><new=Associated><AP=00:0c:e6:06:30:ad><BSSID=00:0c:e6:83
:87:19>
2012-May-13 17:09:15.827945 | 00:1b:77:1f:cd:5b | 1X Authentication |
<auth method=WPA2_EAP>:<pkt type=EAPOL_START> recvd <ESSID=eduroam>
<BSSID=36:06:1f:1f:cd:5b>
2012-May-13 17:09:15.827952 | 00:1b:77:1f:cd:5b | 1X Authentication |
<EAP code=request> <EAP ID=1> <EAP type=Identity> sent
2012-May-13 17:09:15.827955 | 00:1b:77:1f:cd:5b | 1X Authentication |
<pkt type=EAP_PACKET> <EAP code=response><EAP ID=1>
2012-May-13 17:09:15.827959 | 00:1b:77:1f:cd:5b | 1X Authentication |
Radius <msg code=access_request><msg ID=135> sent
<ip=128.255.41.17>:<port=1812>
2012-May-13 17:09:15.851354 | 00:1b:77:1f:cd:5b | 1X Authentication |
<pkt type=EAP_PACKET> <EAP code=response><EAP ID=1>
2012-May-13 17:09:15.897407 | 00:1b:77:1f:cd:5b | 1X Authentication |
<pkt type=EAP_PACKET> <EAP code=request><EAP ID=2> <info=relay eap-request
from Radius> sent
2012-May-13 17:09:15.920135 | 00:1b:77:1f:cd:5b | 1X Authentication |
<pkt type=EAP_PACKET> <EAP code=response><EAP ID=2>
2012-May-13 17:09:15.920139 | 00:1b:77:1f:cd:5b | 1X Authentication |
Radius <msg code=access_request><msg ID=136> sent
<ip=128.255.41.17>:<port=1812>
2012-May-13 17:09:15.998738 | 00:1b:77:1f:cd:5b | 1X Authentication |
<pkt type=EAP_PACKET> <EAP code=request><EAP ID=3> <info=relay eap-request
from Radius> sent
2012-May-13 17:09:16.024576 | 00:1b:77:1f:cd:5b | 1X Authentication |
<pkt type=EAP_PACKET> <EAP code=response><EAP ID=3>
2012-May-13 17:09:16.024581 | 00:1b:77:1f:cd:5b | 1X Authentication |
Radius <msg code=access_request><msg ID=137> sent
<ip=128.255.41.17>:<port=1812>
2012-May-13 17:09:16.799754 | 00:1b:77:1f:cd:5b | 1X Authentication |
<pkt type=EAP_PACKET> <EAP code=success><EAP ID=3> <info=relay eap-request
from Radius> sent
2012-May-13 17:09:16.799762 | 00:1b:77:1f:cd:5b | 1X Authentication |
M1 <msg type=EAPOL_KEY> PTK sent
2012-May-13 17:09:17.809285 | 00:1b:77:1f:cd:5b | 1X Authentication |
M1 <msg type=EAPOL_KEY> PTK sent
2012-May-13 17:09:18.819315 | 00:1b:77:1f:cd:5b | 1X Authentication |
M1 <msg type=EAPOL_KEY> PTK sent
2012-May-13 17:09:19.829282 | 00:1b:77:1f:cd:5b | 1X Authentication |
M1 <msg type=EAPOL_KEY> PTK sent
2012-May-13 17:09:20.838743 | 00:1b:77:1f:cd:5b | 1X Authentication |
Sending Station Disconnect, Reason : 4-way Handshake Timeout, Auth Type
PEAP
2012-May-13 17:09:20.839560 | 00:1b:77:1f:cd:5b | 802.11 State |
Disassoc reason: Unspecified<AID=1><BSSID=36:06:1f:1f:cd:5b>
2012-May-13 17:09:20.842399 | 00:1b:77:1f:cd:5b | 802.11 State |
state change
<old=Associated><new=Unauthenticated><AP=00:0c:e6:06:30:ad><BSSID=00:0c:e6:
83:87:19>
...Repeats
Here is sample of what is going on in the RADIATOR log:
Mon May 14 16:44:14 2012: DEBUG: Packet dump:
*** Received from 128.255.11.74 port 32768 ....
Code: Access-Request
Identifier: 231
Authentic: 7$<222><247>_<236><222><29><175>m<201><159><159><226><181>~
Attributes:
User-Name = "nmjoo at uiowa.edu"
NAS-IP-Address = 128.255.11.74
NAS-Port = 26625
Called-Station-Id = "00-90-0B-07-8C-89:UI-eduroam"
Calling-Station-Id = "00-1B-77-1F-CD-5B"
Framed-MTU = 1250
NAS-Port-Type = Wireless-IEEE-802-11
Framed-Compression = None
Connect-Info = "CONNECT 802.11g"
EAP-Message = <2><1><0><20><1>nmjoo at uiowa.edu
Message-Authenticator =
<189><18>J<236>P<160><132><134>G<228><0>7G<180><14><192>
Mon May 14 16:44:14 2012: DEBUG: Handling request with Handler
'Client-Identifier=fromUIOWA, Called-Station-Id=/eduroam$/i,
Realm=/(uiowa\.edu$)/i ', Identifier ''
Mon May 14 16:44:14 2012: DEBUG: PreProcessing Hook: called.
Mon May 14 16:44:14 2012: DEBUG: Deleting session for nmjoo at uiowa.edu,
128.255.11.74, 26625
Mon May 14 16:44:14 2012: DEBUG: Handling with Radius::AuthLSA:
Mon May 14 16:44:14 2012: DEBUG: Handling with EAP: code 2, 1, 20, 1
Mon May 14 16:44:14 2012: DEBUG: Response type 1
Mon May 14 16:44:14 2012: DEBUG: EAP result: 3, EAP PEAP Challenge
Mon May 14 16:44:14 2012: DEBUG: AuthBy LSA result: CHALLENGE, EAP PEAP
Challenge
Mon May 14 16:44:14 2012: DEBUG: Access challenged for nmjoo at uiowa.edu:
EAP PEAP Challenge
Mon May 14 16:44:14 2012: DEBUG: PostProcessing Hook: called.
Mon May 14 16:44:14 2012: DEBUG: Packet dump:
*** Sending to 128.255.11.74 port 32768 ....
Code: Access-Challenge
Identifier: 231
Authentic: <206>(H<152><212><219><185><18>)<29>'<167>N<3><200><187>
Attributes:
EAP-Message = <1><2><0><6><25>
Message-Authenticator = <0><0><0><0><0><0><0><0><0><0><0><0><0><0><0><0>
Mon May 14 16:44:14 2012: DEBUG: Packet dump:
*** Received from 128.255.11.74 port 32768 ....
Code: Access-Request
Identifier: 232
Authentic: <150>Q<140><253>^<138><151><164><11>bP9<158><204><233>/
Attributes:
User-Name = "nmjoo at uiowa.edu"
NAS-IP-Address = 128.255.11.74
NAS-Port = 26625
Called-Station-Id = "00-90-0B-07-8C-89:UI-eduroam"
Calling-Station-Id = "00-1B-77-1F-CD-5B"
Framed-MTU = 1250
NAS-Port-Type = Wireless-IEEE-802-11
Framed-Compression = None
Connect-Info = "CONNECT 802.11g"
EAP-Message =
<2><2><0><137><25><128><0><0><0><127><22><3><1><0>z<1><0><0>v<3><1>O<177>|<
174><180><227>m<232><199>M<244>e<130><181><138><235><223><200>%WYO<243><195
><188>D<31><235>%<243><148>#
>v<30>0.\*<176>?<220><136><178><28><211>$)L<219><0><253>3<169>1#<141><206><
>167><3><230><19><232><196><30><0><24><0>/<0>5<0><5><0><10><192><19><192><2
>0><192><9><192><10><0>2<0>8<0><19><0><4><1><0><0><21><255><1><0><1><0><0><
>10><0><6><0><4><0><23><0><24><0><11><0><2><1><0>
Message-Authenticator =
<201><216><193>u<225>V<16><128><189>(<190><235>|<239>;3
Mon May 14 16:44:14 2012: DEBUG: Handling request with Handler
'Client-Identifier=fromUIOWA, Called-Station-Id=/eduroam$/i,
Realm=/(uiowa\.edu$)/i ', Identifier ''
Mon May 14 16:44:14 2012: DEBUG: PreProcessing Hook: called.
Mon May 14 16:44:14 2012: DEBUG: Deleting session for nmjoo at uiowa.edu,
128.255.11.74, 26625
Mon May 14 16:44:14 2012: DEBUG: Handling with Radius::AuthLSA:
Mon May 14 16:44:14 2012: DEBUG: Handling with EAP: code 2, 2, 137, 25
Mon May 14 16:44:14 2012: DEBUG: Response type 25
Mon May 14 16:44:14 2012: DEBUG: EAP TLS SSL_accept result: -1, 2, 8640
Mon May 14 16:44:14 2012: DEBUG: EAP result: 3, EAP PEAP Challenge
Mon May 14 16:44:14 2012: DEBUG: AuthBy LSA result: CHALLENGE, EAP PEAP
Challenge
Mon May 14 16:44:14 2012: DEBUG: Access challenged for nmjoo at uiowa.edu:
EAP PEAP Challenge
Mon May 14 16:44:14 2012: DEBUG: PostProcessing Hook: called.
Mon May 14 16:44:14 2012: DEBUG: Packet dump:
*** Sending to 128.255.11.74 port 32768 ....
Code: Access-Challenge
Identifier: 232
Authentic: <4>:<247><164><143><170><182><198>0T<4>rv<141><21><167>
Attributes:
EAP-Message =
<1><3><0><148><25><128><0><0><0><138><22><3><1><0>J<2><0><0>F<3><1>O<177>|<
174><181><222><229>ai<[$<194>0D<241><153><215>s<25><229>Y8er<234><212>)i<17
1>wM
v<30>0.\*<176>?<220><136><178><28><211>$)L<219><0><253>3<169>1#<141><206><1
67><3><230><19><232><196><30><0>/<0><20><3><1><0><1><1><22><3><1><0>0g2<195
>J<178>v<191><129><210><186><218><164><219><31>G<148><210><5><142><23><244>
><218>8<225><215>C<169><244>!<127><6><197>R*<21><141><159><254><226><254><1
>89><229>9<138><6><139>%Z
Message-Authenticator = <0><0><0><0><0><0><0><0><0><0><0><0><0><0><0><0>
Mon May 14 16:44:14 2012: DEBUG: Packet dump:
*** Received from 128.255.11.74 port 32768 ....
Code: Access-Request
Identifier: 233
Authentic: <255><24><141>+y<143>JX<149>u<181><24><12><11><147><198>
Attributes:
User-Name = "nmjoo at uiowa.edu"
NAS-IP-Address = 128.255.11.74
NAS-Port = 26625
Called-Station-Id = "00-90-0B-07-8C-89:UI-eduroam"
Calling-Station-Id = "00-1B-77-1F-CD-5B"
Framed-MTU = 1250
NAS-Port-Type = Wireless-IEEE-802-11
Framed-Compression = None
Connect-Info = "CONNECT 802.11g"
EAP-Message =
<2><3><0>E<25><128><0><0><0>;<20><3><1><0><1><1><22><3><1><0>0@<3>/<253><14
1><22><179>G8<215><134>?<16>@<254>=<3><225>s'<31>79<228><28>e<12><143><2><1
7><2><18><254>g<7><253>4<202>]><179><244><129>;<205><17><222>y
Message-Authenticator =
<160><24><175><218><228>i<162><219><193><211><9>p<234><151><252><164>
Mon May 14 16:44:14 2012: DEBUG: Handling request with Handler
'Client-Identifier=fromUIOWA, Called-Station-Id=/eduroam$/i,
Realm=/(uiowa\.edu$)/i ', Identifier ''
Mon May 14 16:44:14 2012: DEBUG: PreProcessing Hook: called.
Mon May 14 16:44:14 2012: DEBUG: Deleting session for nmjoo at uiowa.edu,
128.255.11.74, 26625
Mon May 14 16:44:14 2012: DEBUG: Handling with Radius::AuthLSA:
Mon May 14 16:44:14 2012: DEBUG: Handling with EAP: code 2, 3, 69, 25
Mon May 14 16:44:14 2012: DEBUG: Response type 25
Mon May 14 16:44:14 2012: DEBUG: EAP TLS SSL_accept result: 1, 0, 3
Mon May 14 16:44:14 2012: DEBUG: EAP Success, elapsed time 0.20266
Mon May 14 16:44:14 2012: DEBUG: EAP result: 0,
Mon May 14 16:44:14 2012: DEBUG: AuthBy LSA result: ACCEPT,
Mon May 14 16:44:14 2012: DEBUG: Access accepted for nmjoo at uiowa.edu
Mon May 14 16:44:14 2012: DEBUG: PostProcessing Hook: called.
Mon May 14 16:44:14 2012: DEBUG: PostProcessingHook: eap_acct_username:
EAP Identity = nmjoo at uiowa.edu
Mon May 14 16:44:14 2012: DEBUG: PostProcessingHook eap_acct_username:
Copying username: nmjoo at uiowa.edu to outer request
Mon May 14 16:44:14 2012: DEBUG: PostProcessingHook: VLAN Tag Not Found!
Mon May 14 16:44:14 2012: DEBUG: PostProcessingHook: Calling Station ID:
00-1B-77-1F-CD-5B
Mon May 14 16:44:14 2012: DEBUG: PostProcessingHook: Existing Entry Found.
Mon May 14 16:44:14 2012: INFO: PostProcessingHook: Setting Station
00-1B-77-1F-CD-5B VLAN to 212
Mon May 14 16:44:14 2012: DEBUG: Packet dump:
*** Sending to 128.255.11.74 port 32768 ....
Code: Access-Accept
Identifier: 233
Authentic: <141><22><172><214><22>^K<129><4>[<27><21><160>}<177><12>
Attributes:
EAP-Message = <3><3><0><4>
Message-Authenticator = <0><0><0><0><0><0><0><0><0><0><0><0><0><0><0><0>
MS-MPPE-Send-Key =
<217><239><9><186><5><128><235><211>Is<209>R<196><11><194><189>v
k,<12>X<135><143>3<240><1>k<156><144>)<193>
MS-MPPE-Recv-Key =
CD<233><161><241><209><182><<160><202><169><14><166><132><5><149><130>h<171
>QB{<232>D<177><136><4><197><197><177>]<217>
User-Name = "nmjoo at uiowa.edu"
Tunnel-Private-Group-ID = 212
Tunnel-Type = VLAN
Tunnel-Medium-Type = 802
Mon May 14 16:44:15 2012: DEBUG: Packet dump:
*** Received from 128.255.11.74 port 32769 ....
Code: Accounting-Request
Identifier: 234
Authentic: <222><171><157><127> }<134><161><19><184><216><135><9>1Zs
Attributes:
Acct-Status-Type = Start
Acct-Session-Id = "4F9811F3-000003DC"
Acct-Authentic = RADIUS
User-Name = "nmjoo at uiowa.edu"
NAS-IP-Address = 128.255.11.74
NAS-Port = 26625
NAS-Port-Type = Wireless-IEEE-802-11
NAS-Identifier = "00-90-0B-07-8C-89"
Called-Station-Id = "00-90-0B-07-8C-89:UI-eduroam"
Calling-Station-Id = "00-1B-77-1F-CD-5B"
Connect-Info = "CONNECT 802.11g"
Acct-Delay-Time = 0
Meru-AP-Id = 569
Meru-AP-Name = "AP-569"
Mon May 14 16:44:15 2012: DEBUG: Handling request with Handler
'Client-Identifier=fromUIOWA, Called-Station-Id=/eduroam$/i,
Realm=/(uiowa\.edu$)/i ', Identifier ''
Mon May 14 16:44:15 2012: DEBUG: PreProcessing Hook: called.
Mon May 14 16:44:15 2012: DEBUG: PreProcessingHook: Accounting-Request
packet found!
Mon May 14 16:44:15 2012: DEBUG: PreProcessingHook: Looking up Inner ID in
inner ID DB
Mon May 14 16:44:15 2012: INFO: PreProcessingHook: Database Issue: Finding
Inner ID
Mon May 14 16:44:15 2012: DEBUG: PreProcessingHook: Did Not Find Inner ID
in Cache DB, Using: nmjoo at uiowa.edu
Mon May 14 16:44:15 2012: DEBUG: PreProcessingHook:
Accounting-Status-Type: Start
Mon May 14 16:44:15 2012: DEBUG: PreProcessingHook: Calling Station ID:
00-1B-77-1F-CD-5B
Mon May 14 16:44:15 2012: INFO: PreProcessingHook: Station
00-1B-77-1F-CD-5B Found, updating Timestamp.
Mon May 14 16:44:15 2012: DEBUG: Adding session for nmjoo at uiowa.edu,
128.255.11.74, 26625
Mon May 14 16:44:15 2012: DEBUG: Handling with Radius::AuthLSA:
Mon May 14 16:44:15 2012: DEBUG: AuthBy LSA result: ACCEPT,
Mon May 14 16:44:15 2012: DEBUG: Accounting accepted
Mon May 14 16:44:15 2012: DEBUG: PostProcessing Hook: called.
Mon May 14 16:44:15 2012: DEBUG: Packet dump:
*** Sending to 128.255.11.74 port 32769 ....
Code: Accounting-Response
Identifier: 234
Authentic: <232><<0><180><140><145>v/<2><182><141>9(tV&
Attributes:
Mon May 14 16:44:19 2012: DEBUG: Packet dump:
*** Received from 128.255.11.74 port 32769 ....
Code: Accounting-Request
Identifier: 235
Authentic: uST<18>&<211><176><27>B<174><188><178><152><29>)P
Attributes:
Acct-Status-Type = Stop
Acct-Session-Id = "4F9811F3-000003DC"
Acct-Authentic = RADIUS
User-Name = "nmjoo at uiowa.edu"
NAS-IP-Address = 128.255.11.74
NAS-Port = 26625
NAS-Port-Type = Wireless-IEEE-802-11
NAS-Identifier = "00-90-0B-07-8C-89"
Called-Station-Id = "00-90-0B-07-8C-89:UI-eduroam"
Calling-Station-Id = "00-1B-77-1F-CD-5B"
Connect-Info = "CONNECT 802.11g"
Acct-Session-Time = 4
Acct-Delay-Time = 0
Acct-Terminate-Cause = User-Request
Acct-Input-Packets = 0
Acct-Output-Packets = 0
Acct-Input-Octets = 0
Acct-Output-Octets = 0
Meru-AP-Id = 569
Meru-AP-Name = "AP-569"
Mon May 14 16:44:19 2012: DEBUG: Handling request with Handler
'Client-Identifier=fromUIOWA, Called-Station-Id=/eduroam$/i,
Realm=/(uiowa\.edu$)/i ', Identifier ''
Mon May 14 16:44:19 2012: DEBUG: PreProcessing Hook: called.
Mon May 14 16:44:19 2012: DEBUG: PreProcessingHook: Accounting-Request
packet found!
Mon May 14 16:44:19 2012: DEBUG: PreProcessingHook: Looking up Inner ID in
inner ID DB
Mon May 14 16:44:19 2012: INFO: PreProcessingHook: Database Issue: Finding
Inner ID
Mon May 14 16:44:19 2012: DEBUG: PreProcessingHook: Did Not Find Inner ID
in Cache DB, Using: nmjoo at uiowa.edu
Mon May 14 16:44:19 2012: DEBUG: PreProcessingHook:
Accounting-Status-Type: Stop
Mon May 14 16:44:19 2012: DEBUG: PreProcessingHook: Deleting User from
inner ID Cache DB
Mon May 14 16:44:19 2012: INFO: PreProcessingHook: Database Issue:
Deleting Inner DB
Mon May 14 16:44:19 2012: DEBUG: Deleting session for nmjoo at uiowa.edu,
128.255.11.74, 26625
Mon May 14 16:44:19 2012: DEBUG: Handling with Radius::AuthLSA:
Mon May 14 16:44:19 2012: DEBUG: AuthBy LSA result: ACCEPT,
Mon May 14 16:44:19 2012: DEBUG: Accounting accepted
Mon May 14 16:44:19 2012: DEBUG: PostProcessing Hook: called.
Mon May 14 16:44:19 2012: DEBUG: Packet dump:
*** Sending to 128.255.11.74 port 32769 ....
Code: Accounting-Response
Identifier: 235
Authentic: D<181>L<209><151>$i<29><242><222>N*<135><200>g<156>
Attributes:
Mon May 14 16:44:19 2012: DEBUG: Packet dump:
*** Received from 128.255.11.74 port 32768 ....
Code: Access-Request
Identifier: 236
Authentic: <143><133><18><140><8>B<175><156>5><21><15><185><248><144><224>
Attributes:
User-Name = "nmjoo at uiowa.edu"
NAS-IP-Address = 128.255.11.74
NAS-Port = 26625
Called-Station-Id = "00-90-0B-07-8C-89:UI-eduroam"
Calling-Station-Id = "00-1B-77-1F-CD-5B"
Framed-MTU = 1250
NAS-Port-Type = Wireless-IEEE-802-11
Framed-Compression = None
Connect-Info = "CONNECT 802.11g"
EAP-Message = <2><1><0><20><1>nmjoo at uiowa.edu
Message-Authenticator = Y<20>b<254><7><154>i<14><24>=@<217>51<143><182>
Mon May 14 16:44:19 2012: DEBUG: Handling request with Handler
'Client-Identifier=fromUIOWA, Called-Station-Id=/eduroam$/i,
Realm=/(uiowa\.edu$)/i ', Identifier ''
Mon May 14 16:44:19 2012: DEBUG: PreProcessing Hook: called.
Mon May 14 16:44:19 2012: DEBUG: Deleting session for nmjoo at uiowa.edu,
128.255.11.74, 26625
Mon May 14 16:44:19 2012: DEBUG: Handling with Radius::AuthLSA:
Mon May 14 16:44:19 2012: DEBUG: Handling with EAP: code 2, 1, 20, 1
Mon May 14 16:44:19 2012: DEBUG: Response type 1
Mon May 14 16:44:19 2012: DEBUG: EAP result: 3, EAP PEAP Challenge
Mon May 14 16:44:19 2012: DEBUG: AuthBy LSA result: CHALLENGE, EAP PEAP
Challenge
Mon May 14 16:44:19 2012: DEBUG: Access challenged for nmjoo at uiowa.edu:
EAP PEAP Challenge
Mon May 14 16:44:19 2012: DEBUG: PostProcessing Hook: called.
Mon May 14 16:44:19 2012: DEBUG: Packet dump:
*** Sending to 128.255.11.74 port 32768 ....
Code: Access-Challenge
Identifier: 236
Authentic: (<195><188><140><154><221><6>}MY<238><183><128>$B<20>
Attributes:
EAP-Message = <1><2><0><6><25>
Message-Authenticator = <0><0><0><0><0><0><0><0><0><0><0><0><0><0><0><0>
Mon May 14 16:44:19 2012: DEBUG: Packet dump:
*** Received from 128.255.11.74 port 32768 ....
Code: Access-Request
Identifier: 237
Authentic: @A<235><11><190>E/Y<238><13>T<208><173>vm<188>
Attributes:
User-Name = "nmjoo at uiowa.edu"
NAS-IP-Address = 128.255.11.74
NAS-Port = 26625
Called-Station-Id = "00-90-0B-07-8C-89:UI-eduroam"
Calling-Station-Id = "00-1B-77-1F-CD-5B"
Framed-MTU = 1250
NAS-Port-Type = Wireless-IEEE-802-11
Framed-Compression = None
Connect-Info = "CONNECT 802.11g"
EAP-Message =
<2><2><0><137><25><128><0><0><0><127><22><3><1><0>z<1><0><0>v<3><1>O<177>|<
179><176><186><29><128><142>NJp<250>a<205><168>XS<6>8(<157><128><143><199><
1>1<192><30><0><171>r
v<30>0.\*<176>?<220><136><178><28><211>$)L<219><0><253>3<169>1#<141><206><1
67><3><230><19><232><196><30><0><24><0>/<0>5<0><5><0><10><192><19><192><20>
<192><9><192><10><0>2<0>8<0><19><0><4><1><0><0><21><255><1><0><1><0><0><10>
<0><6><0><4><0><23><0><24><0><11><0><2><1><0>
Message-Authenticator = <17><177><197><177><220><22>tu<186>kQ'<5>*[<245>
Mon May 14 16:44:19 2012: DEBUG: Handling request with Handler
'Client-Identifier=fromUIOWA, Called-Station-Id=/eduroam$/i,
Realm=/(uiowa\.edu$)/i ', Identifier ''
Mon May 14 16:44:19 2012: DEBUG: PreProcessing Hook: called.
Mon May 14 16:44:19 2012: DEBUG: Deleting session for nmjoo at uiowa.edu,
128.255.11.74, 26625
Mon May 14 16:44:19 2012: DEBUG: Handling with Radius::AuthLSA:
Mon May 14 16:44:19 2012: DEBUG: Handling with EAP: code 2, 2, 137, 25
Mon May 14 16:44:19 2012: DEBUG: Response type 25
Mon May 14 16:44:19 2012: DEBUG: EAP TLS SSL_accept result: -1, 2, 8640
Mon May 14 16:44:19 2012: DEBUG: EAP result: 3, EAP PEAP Challenge
Mon May 14 16:44:19 2012: DEBUG: AuthBy LSA result: CHALLENGE, EAP PEAP
Challenge
Mon May 14 16:44:19 2012: DEBUG: Access challenged for nmjoo at uiowa.edu:
EAP PEAP Challenge
Mon May 14 16:44:19 2012: DEBUG: PostProcessing Hook: called.
Mon May 14 16:44:19 2012: DEBUG: Packet dump:
*** Sending to 128.255.11.74 port 32768 ....
Code: Access-Challenge
Identifier: 237
Authentic: I<0>@ai<6>c><11><190><165>_<&Cm
Attributes:
EAP-Message =
<1><3><0><148><25><128><0><0><0><138><22><3><1><0>J<2><0><0>F<3><1>O<177>|<
179><145>Q<127><10>8<27>*<201>`|<181><214><164><202>G<205><217><234><188>[<
157><127>?B<16><167>7<254>
v<30>0.\*<176>?<220><136><178><28><211>$)L<219><0><253>3<169>1#<141><206><1
67><3><230><19><232><196><30><0>/<0><20><3><1><0><1><1><22><3><1><0>0U<229>
<254>n<29><22>r<233><213><213>z6<160><222><180><127><26><12><143><132><211>
<12><182><231>lI<7><164><16><174><136><249>.<199><15><20><181><228>m<216>k<
<230>!<152>/<215><172>
Message-Authenticator = <0><0><0><0><0><0><0><0><0><0><0><0><0><0><0><0>
Mon May 14 16:44:19 2012: DEBUG: Packet dump:
*** Received from 128.255.11.74 port 32768 ....
Code: Access-Request
Identifier: 238
Authentic: <207>T<200><7><201>e$6a<17>:<228><163>p<241>d
Attributes:
User-Name = "nmjoo at uiowa.edu"
NAS-IP-Address = 128.255.11.74
NAS-Port = 26625
Called-Station-Id = "00-90-0B-07-8C-89:UI-eduroam"
Calling-Station-Id = "00-1B-77-1F-CD-5B"
Framed-MTU = 1250
NAS-Port-Type = Wireless-IEEE-802-11
Framed-Compression = None
Connect-Info = "CONNECT 802.11g"
EAP-Message =
<2><3><0>E<25><128><0><0><0>;<20><3><1><0><1><1><22><3><1><0>0<249><232><15
1>2<6><161><31>L<171><0><243><219><252><188><149><247><237><166><248><1><23
7><138><20>l%<19><179><147><233>A_FE<16><134>P<138>><188>t<177><234><192><1
90><178><222><245><228>
Message-Authenticator = <164>VT{5>9Gul=p<244>t<223><193>
Mon May 14 16:44:19 2012: DEBUG: Handling request with Handler
'Client-Identifier=fromUIOWA, Called-Station-Id=/eduroam$/i,
Realm=/(uiowa\.edu$)/i ', Identifier ''
Mon May 14 16:44:19 2012: DEBUG: PreProcessing Hook: called.
Mon May 14 16:44:19 2012: DEBUG: Deleting session for nmjoo at uiowa.edu,
128.255.11.74, 26625
Mon May 14 16:44:19 2012: DEBUG: Handling with Radius::AuthLSA:
Mon May 14 16:44:19 2012: DEBUG: Handling with EAP: code 2, 3, 69, 25
Mon May 14 16:44:19 2012: DEBUG: Response type 25
Mon May 14 16:44:19 2012: DEBUG: EAP TLS SSL_accept result: 1, 0, 3
Mon May 14 16:44:19 2012: DEBUG: EAP Success, elapsed time 0.219555
Mon May 14 16:44:19 2012: DEBUG: EAP result: 0,
Mon May 14 16:44:19 2012: DEBUG: AuthBy LSA result: ACCEPT,
Mon May 14 16:44:19 2012: DEBUG: Access accepted for nmjoo at uiowa.edu
Mon May 14 16:44:19 2012: DEBUG: PostProcessing Hook: called.
Mon May 14 16:44:19 2012: DEBUG: PostProcessingHook: eap_acct_username:
EAP Identity = nmjoo at uiowa.edu
Mon May 14 16:44:19 2012: DEBUG: PostProcessingHook eap_acct_username:
Copying username: nmjoo at uiowa.edu to outer request
Mon May 14 16:44:19 2012: DEBUG: PostProcessingHook: VLAN Tag Not Found!
Mon May 14 16:44:19 2012: DEBUG: PostProcessingHook: Calling Station ID:
00-1B-77-1F-CD-5B
Mon May 14 16:44:19 2012: DEBUG: PostProcessingHook: Existing Entry Found.
Mon May 14 16:44:19 2012: INFO: PostProcessingHook: Setting Station
00-1B-77-1F-CD-5B VLAN to 212
Mon May 14 16:44:19 2012: DEBUG: Packet dump:
*** Sending to 128.255.11.74 port 32768 ....
Code: Access-Accept
Identifier: 238
Authentic: E<154>Lw<@n<20><177><131><8>y<134><7><218><223>
Attributes:
EAP-Message = <3><3><0><4>
Message-Authenticator = <0><0><0><0><0><0><0><0><0><0><0><0><0><0><0><0>
MS-MPPE-Send-Key = <10><251><237><156><180><251><154>s<184><206><179>
<233><171><236><219>N<174><6><1>*<232>
<9><193><26><250>f<215><196><224><152>
MS-MPPE-Recv-Key =
%<232>1/z<253>pk<140><180><227>I<163><183><166><173><143><143><156><207><16
4>L<250><214><3>q~<251><181><19><173><231>
User-Name = "nmjoo at uiowa.edu"
Tunnel-Private-Group-ID = 212
Tunnel-Type = VLAN
Tunnel-Medium-Type = 802
Mon May 14 16:44:20 2012: DEBUG: Packet dump:
*** Received from 128.255.11.74 port 32769 ....
Code: Accounting-Request
Identifier: 239
Authentic: <179>p<241><155>W<172><147><24><252>S<170><30>Ll<187>B
Attributes:
Acct-Status-Type = Start
Acct-Session-Id = "4F9811F3-000003DD"
Acct-Authentic = RADIUS
User-Name = "nmjoo at uiowa.edu"
NAS-IP-Address = 128.255.11.74
NAS-Port = 26625
NAS-Port-Type = Wireless-IEEE-802-11
NAS-Identifier = "00-90-0B-07-8C-89"
Called-Station-Id = "00-90-0B-07-8C-89:UI-eduroam"
Calling-Station-Id = "00-1B-77-1F-CD-5B"
Connect-Info = "CONNECT 802.11g"
Acct-Delay-Time = 0
Meru-AP-Id = 569
Meru-AP-Name = "AP-569"
Mon May 14 16:44:20 2012: DEBUG: Handling request with Handler
'Client-Identifier=fromUIOWA, Called-Station-Id=/eduroam$/i,
Realm=/(uiowa\.edu$)/i ', Identifier ''
Mon May 14 16:44:20 2012: DEBUG: PreProcessing Hook: called.
Mon May 14 16:44:20 2012: DEBUG: PreProcessingHook: Accounting-Request
packet found!
Mon May 14 16:44:20 2012: DEBUG: PreProcessingHook: Looking up Inner ID in
inner ID DB
Mon May 14 16:44:20 2012: INFO: PreProcessingHook: Database Issue: Finding
Inner ID
Mon May 14 16:44:20 2012: DEBUG: PreProcessingHook: Did Not Find Inner ID
in Cache DB, Using: nmjoo at uiowa.edu
Mon May 14 16:44:20 2012: DEBUG: PreProcessingHook:
Accounting-Status-Type: Start
Mon May 14 16:44:20 2012: DEBUG: PreProcessingHook: Calling Station ID:
00-1B-77-1F-CD-5B
Mon May 14 16:44:20 2012: INFO: PreProcessingHook: Station
00-1B-77-1F-CD-5B Found, updating Timestamp.
Mon May 14 16:44:20 2012: DEBUG: Adding session for nmjoo at uiowa.edu,
128.255.11.74, 26625
Mon May 14 16:44:20 2012: DEBUG: Handling with Radius::AuthLSA:
Mon May 14 16:44:20 2012: DEBUG: AuthBy LSA result: ACCEPT,
Mon May 14 16:44:20 2012: DEBUG: Accounting accepted
Mon May 14 16:44:20 2012: DEBUG: PostProcessing Hook: called.
Mon May 14 16:44:20 2012: DEBUG: Packet dump:
*** Sending to 128.255.11.74 port 32769 ....
Code: Accounting-Response
Identifier: 239
Authentic: ,<238><31><19><195><245><151><187><26><21>uU<26><206>1<129>
Attributes:
Mon May 14 16:44:24 2012: DEBUG: Packet dump:
*** Received from 128.255.11.74 port 32769 ....
Code: Accounting-Request
Identifier: 240
Authentic: <205>s?]<14>vE<186>}<164><255><29><217><223><186><149>
Attributes:
Acct-Status-Type = Stop
Acct-Session-Id = "4F9811F3-000003DD"
Acct-Authentic = RADIUS
User-Name = "nmjoo at uiowa.edu"
NAS-IP-Address = 128.255.11.74
NAS-Port = 26625
NAS-Port-Type = Wireless-IEEE-802-11
NAS-Identifier = "00-90-0B-07-8C-89"
Called-Station-Id = "00-90-0B-07-8C-89:UI-eduroam"
Calling-Station-Id = "00-1B-77-1F-CD-5B"
Connect-Info = "CONNECT 802.11g"
Acct-Session-Time = 4
Acct-Delay-Time = 0
Acct-Terminate-Cause = User-Request
Acct-Input-Packets = 0
Acct-Output-Packets = 0
Acct-Input-Octets = 0
Acct-Output-Octets = 0
Meru-AP-Id = 569
Meru-AP-Name = "AP-569"
Mon May 14 16:44:24 2012: DEBUG: Handling request with Handler
'Client-Identifier=fromUIOWA, Called-Station-Id=/eduroam$/i,
Realm=/(uiowa\.edu$)/i ', Identifier ''
Mon May 14 16:44:24 2012: DEBUG: PreProcessing Hook: called.
Mon May 14 16:44:24 2012: DEBUG: PreProcessingHook: Accounting-Request
packet found!
Mon May 14 16:44:24 2012: DEBUG: PreProcessingHook: Looking up Inner ID in
inner ID DB
Mon May 14 16:44:24 2012: INFO: PreProcessingHook: Database Issue: Finding
Inner ID
Mon May 14 16:44:24 2012: DEBUG: PreProcessingHook: Did Not Find Inner ID
in Cache DB, Using: nmjoo at uiowa.edu
Mon May 14 16:44:24 2012: DEBUG: PreProcessingHook:
Accounting-Status-Type: Stop
Mon May 14 16:44:24 2012: DEBUG: PreProcessingHook: Deleting User from
inner ID Cache DB
Mon May 14 16:44:24 2012: INFO: PreProcessingHook: Database Issue:
Deleting Inner DB
Mon May 14 16:44:24 2012: DEBUG: Deleting session for nmjoo at uiowa.edu,
128.255.11.74, 26625
Mon May 14 16:44:24 2012: DEBUG: Handling with Radius::AuthLSA:
Mon May 14 16:44:24 2012: DEBUG: AuthBy LSA result: ACCEPT,
Mon May 14 16:44:24 2012: DEBUG: Accounting accepted
Mon May 14 16:44:24 2012: DEBUG: PostProcessing Hook: called.
Mon May 14 16:44:24 2012: DEBUG: Packet dump:
*** Sending to 128.255.11.74 port 32769 ....
Code: Accounting-Response
Identifier: 240
Authentic: 8<200><141>x<215><196><23>c<147><140>N^<129>7q<177>
Attributes:
.... Also Repeats.
Could it be an issue with the MPPE-Keys ?
Disabling TLS Session Resumption seems to fix the issue, but I would like
to have fast reconnects.
Thanks.
-Neil
--
Neil Johnson
Network Engineer
The University of Iowa
Phone: 319 384-0938
Fax: 319 335-2951
Mobile: 319 540-2081
E-Mail: neil-johnson at uiowa.edu
More information about the radiator
mailing list