Hi,
Now this time with round robin setup. What I am seeing is that each
access request are being sent out in round robin even within the same
authentication session. So, server1 gets the first access-request and
sends access-challenge out and the access-request in response to the
challenge gets sent to server2. Now, server1 waits for the
access-request while the server2 does not know about the access-request
it gets and drops. So, authentication never finishes.
The attached files are the debug output from home server1 and server 2
and the proxy.
> -----Original Message-----
> From: [EMAIL PROTECTED] [mailto:freeradius-
> [EMAIL PROTECTED] On Behalf Of Htin Hlaing
> Sent: Wednesday, July 07, 2004 2:32 PM
> To: [EMAIL PROTECTED]
> Subject: RE: problem with proxying using fail_over setup
>
> Thanks for that info Alan. That makes sense. Also, what I was
looking
> for is that the second server set up will be tried automatically as
the
> first one is marked death. But, it returns access-reject and the
client
> has to initiate authentication again while the first one is marked
dead
> for the dead time. Any way for me to achieve what I am looking for?
>
> Thanks,
> Htin
>
rad_recv: Access-Request packet from host 192.168.10.118:1814, id=5, length=206
--- Walking the entire request list ---
Waking up in 31 seconds...
Thread 5 got semaphore
Thread 5 handling request 39, (8 handled so far)
Framed-MTU = 1466
NAS-IP-Address = 192.168.10.113
NAS-Identifier = "D-link Corp. Access Point"
User-Name = "user_1"
Service-Type = Framed-User
NAS-Port = 65
NAS-Port-Type = Wireless-802.11
NAS-Port-Id = "ether2_65"
Called-Station-Id = "00-05-5d-99-5f-3a"
Calling-Station-Id = "00-30-65-24-4c-5b"
Connect-Info = "CONNECT Ethernet 0Mbps Full duplex"
EAP-Message = 0x0202000b01757365725f31
Message-Authenticator = 0xf99be789d247177bdd244c5bc5f62a20
Proxy-State = 0x313635
Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 39
modcall[authorize]: module "preprocess" returns ok for request 39
radius_xlat:
'/home/hhlaing/Install/radius-June-21-configs/log/radius/radacct/192.168.10.118/auth-detail-20040707'
rlm_detail:
/home/hhlaing/Install/radius-June-21-configs/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d
expands to
/home/hhlaing/Install/radius-June-21-configs/log/radius/radacct/192.168.10.118/auth-detail-20040707
modcall[authorize]: module "auth_log" returns ok for request 39
modcall[authorize]: module "chap" returns noop for request 39
modcall[authorize]: module "mschap" returns noop for request 39
rlm_realm: No '@' in User-Name = "user_1", looking up realm NULL
rlm_realm: No such realm "NULL"
modcall[authorize]: module "suffix" returns noop for request 39
rlm_eap: EAP packet type response id 2 length 11
rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
modcall[authorize]: module "eap" returns updated for request 39
users: Matched user_1 at 104
modcall[authorize]: module "files" returns ok for request 39
modcall: group authorize returns updated for request 39
rad_check_password: Found Auth-Type EAP
auth: type "EAP"
Processing the authenticate section of radiusd.conf
modcall: entering group authenticate for request 39
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 39
modcall: group authenticate returns handled for request 39
Sending Access-Challenge of id 5 to 192.168.10.118:1814
EAP-Message = 0x010300061920
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xbffaa2e18c3fe0a78e5183ee7aee01ac
Proxy-State = 0x313635
Finished request 39
Going to the next request
Thread 5 waiting to be assigned a request
--- Walking the entire request list ---
Cleaning up request 39 ID 5 with timestamp 40ec8b45
Nothing to do. Sleeping until we see a request.
rad_recv: Access-Request packet from host 192.168.10.118:1814, id=4, length=315
--- Walking the entire request list ---
Waking up in 31 seconds...
Thread 3 got semaphore
Thread 3 handling request 7, (2 handled so far)
Framed-MTU = 1466
NAS-IP-Address = 192.168.10.113
NAS-Identifier = "D-link Corp. Access Point"
User-Name = "user_1"
Service-Type = Framed-User
NAS-Port = 65
NAS-Port-Type = Wireless-802.11
NAS-Port-Id = "ether2_65"
Called-Station-Id = "00-05-5d-99-5f-3a"
Calling-Station-Id = "00-30-65-24-4c-5b"
Connect-Info = "CONNECT Ethernet 0Mbps Full duplex"
State = 0xbffaa2e18c3fe0a78e5183ee7aee01ac
EAP-Message =
0x0203006619800000005c160301005701000053030140ec8baa55d9dce47661e05d6f5d2789eb9c12a381fe48eacd30a88ffca482dd00002c00050004000aff830009ff82000300080006ff8000010016001500140013001200110018001b001a001700190100
Message-Authenticator = 0xe4b4696314f6ee96962b413e312bfad8
Proxy-State = 0x313636
Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 7
modcall[authorize]: module "preprocess" returns ok for request 7
radius_xlat:
'/home/hhlaing/Install/radius-June-21-configs/log/radius/radacct/192.168.10.118/auth-detail-20040707'
rlm_detail:
/home/hhlaing/Install/radius-June-21-configs/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d
expands to
/home/hhlaing/Install/radius-June-21-configs/log/radius/radacct/192.168.10.118/auth-detail-20040707
modcall[authorize]: module "auth_log" 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 = "user_1", 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 3 length 102
rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
modcall[authorize]: module "eap" returns updated for request 7
users: Matched user_1 at 104
modcall[authorize]: module "files" 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 not found in the list
rlm_eap: Either EAP-request timed out OR EAP-response to an unknown EAP-request
rlm_eap: Failed in handler
modcall[authenticate]: module "eap" returns invalid for request 7
modcall: group authenticate returns invalid for request 7
auth: Failed to validate the user.
Login incorrect: [user_1] (from client HtinCS port 65 cli 00-30-65-24-4c-5b)
Processing the post-auth section of radiusd.conf
modcall: entering group Post-Auth-Type for request 7
radius_xlat:
'/home/hhlaing/Install/radius-June-21-configs/log/radius/radacct/192.168.10.118/reply-detail-20040707'
rlm_detail:
/home/hhlaing/Install/radius-June-21-configs/log/radius/radacct/%{Client-IP-Address}/reply-detail-%Y%m%d
expands to
/home/hhlaing/Install/radius-June-21-configs/log/radius/radacct/192.168.10.118/reply-detail-20040707
modcall[post-auth]: module "reply_log" returns ok for request 7
modcall: group Post-Auth-Type returns ok for request 7
Delaying request 7 for 1 seconds
Finished request 7
Going to the next request
Thread 3 waiting to be assigned a request
rad_recv: Access-Request packet from host 192.168.10.118:1814, id=4, length=315
Sending Access-Reject of id 4 to 192.168.10.118:1814
Proxy-State = 0x313636
--- Walking the entire request list ---
Cleaning up request 7 ID 4 with timestamp 40ec8b45
Nothing to do. Sleeping until we see a request.
rad_recv: Access-Request packet from host 192.168.10.113:1026, id=165, length=201
--- Walking the entire request list ---
Waking up in 31 seconds...
Thread 4 got semaphore
Thread 4 handling request 9, (4 handled so far)
Framed-MTU = 1466
NAS-IP-Address = 192.168.10.113
NAS-Identifier = "D-link Corp. Access Point"
User-Name = "user_1"
Service-Type = Framed-User
NAS-Port = 65
NAS-Port-Type = Wireless-802.11
NAS-Port-Id = "ether2_65"
Called-Station-Id = "00-05-5d-99-5f-3a"
Calling-Station-Id = "00-30-65-24-4c-5b"
Connect-Info = "CONNECT Ethernet 0Mbps Full duplex"
EAP-Message = 0x0202000b01757365725f31
Message-Authenticator = 0x64b87a97eb6e7f5273ea1cd48abd1f89
Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 9
rlm_realm: No '@' in User-Name = "user_1", looking up realm NULL
rlm_realm: Found realm "NULL"
rlm_realm: Proxying request from user user_1 to realm NULL
rlm_realm: Adding Realm = "NULL"
rlm_realm: Preparing to proxy authentication request to realm "NULL"
modcall[authorize]: module "suffix" returns updated for request 9
radius_xlat: '/var/log/radius//auth-detail-20040707'
rlm_detail: /var/log/radius/%{Client-IP-Address}/auth-detail-%Y%m%d expands to
/var/log/radius//auth-detail-20040707
modcall[authorize]: module "auth_log" returns ok for request 9
modcall[authorize]: module "chap" returns noop for request 9
modcall[authorize]: module "mschap" returns noop for request 9
rlm_eap: Request is supposed to be proxied to Realm NULL. Not doing EAP.
modcall[authorize]: module "eap" returns noop for request 9
xmlrpcAuthorize called.
FRXmlRpcModule::authorize called.
FRXmlRpcModule::authorize vpUsername found.
Proxying is turned on.
modcall[authorize]: module "xmlrpc" returns noop for request 9
modcall: group authorize returns updated for request 9
Processing the pre-proxy section of radiusd.conf
modcall: entering group pre-proxy for request 9
radius_xlat: '/var/log/radius//pre-proxy-detail-20040707'
rlm_detail: /var/log/radius/%{Client-IP-Address}/pre-proxy-detail-%Y%m%d expands to
/var/log/radius//pre-proxy-detail-20040707
modcall[pre-proxy]: module "pre_proxy_log" returns ok for request 9
modcall: group pre-proxy returns ok for request 9
Sending Access-Request of id 5 to 192.168.10.43:2004
Framed-MTU = 1466
NAS-IP-Address = 192.168.10.113
NAS-Identifier = "D-link Corp. Access Point"
User-Name = "user_1"
Service-Type = Framed-User
NAS-Port = 65
NAS-Port-Type = Wireless-802.11
NAS-Port-Id = "ether2_65"
Called-Station-Id = "00-05-5d-99-5f-3a"
Calling-Station-Id = "00-30-65-24-4c-5b"
Connect-Info = "CONNECT Ethernet 0Mbps Full duplex"
EAP-Message = 0x0202000b01757365725f31
Message-Authenticator = 0x00000000000000000000000000000000
Proxy-State = 0x313635
Thread 4 waiting to be assigned a request
rad_recv: Access-Challenge packet from host 192.168.10.43:2004, id=5, length=69
Waking up in 31 seconds...
Thread 5 got semaphore
Thread 5 handling request 9, (4 handled so far)
EAP-Message = 0x010300061920
Message-Authenticator = 0x4ddfefd026fe523e4443127277faad06
State = 0xbffaa2e18c3fe0a78e5183ee7aee01ac
Proxy-State = 0x313635
Processing the post-proxy section of radiusd.conf
modcall: entering group post-proxy for request 9
radius_xlat: '/var/log/radius//post-proxy-detail-20040707'
rlm_detail: /var/log/radius/%{Client-IP-Address}/post-proxy-detail-%Y%m%d expands to
/var/log/radius//post-proxy-detail-20040707
modcall[post-proxy]: module "post_proxy_log" returns ok for request 9
modcall[post-proxy]: module "eap" returns noop for request 9
FRXmlRpcModule::postProxy called.
FRXmlRpcModule::logOnStatus got non Accept/Reject packet.
modcall[post-proxy]: module "xmlrpc" returns noop for request 9
modcall: group post-proxy returns ok for request 9
Sending Access-Challenge of id 165 to 192.168.10.113:1026
EAP-Message = 0x010300061920
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xbffaa2e18c3fe0a78e5183ee7aee01ac
Finished request 9
Going to the next request
Thread 5 waiting to be assigned a request
rad_recv: Access-Request packet from host 192.168.10.113:1026, id=166, length=310
Waking up in 31 seconds...
Thread 1 got semaphore
Thread 1 handling request 10, (5 handled so far)
Framed-MTU = 1466
NAS-IP-Address = 192.168.10.113
NAS-Identifier = "D-link Corp. Access Point"
User-Name = "user_1"
Service-Type = Framed-User
NAS-Port = 65
NAS-Port-Type = Wireless-802.11
NAS-Port-Id = "ether2_65"
Called-Station-Id = "00-05-5d-99-5f-3a"
Calling-Station-Id = "00-30-65-24-4c-5b"
Connect-Info = "CONNECT Ethernet 0Mbps Full duplex"
State = 0xbffaa2e18c3fe0a78e5183ee7aee01ac
EAP-Message =
0x0203006619800000005c160301005701000053030140ec8baa55d9dce47661e05d6f5d2789eb9c12a381fe48eacd30a88ffca482dd00002c00050004000aff830009ff82000300080006ff8000010016001500140013001200110018001b001a001700190100
Message-Authenticator = 0xccbb46db5bfea7be3d22a2b7f1796b66
Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 10
rlm_realm: No '@' in User-Name = "user_1", looking up realm NULL
rlm_realm: Found realm "NULL"
rlm_realm: Proxying request from user user_1 to realm NULL
rlm_realm: Adding Realm = "NULL"
rlm_realm: Preparing to proxy authentication request to realm "NULL"
modcall[authorize]: module "suffix" returns updated for request 10
radius_xlat: '/var/log/radius//auth-detail-20040707'
rlm_detail: /var/log/radius/%{Client-IP-Address}/auth-detail-%Y%m%d expands to
/var/log/radius//auth-detail-20040707
modcall[authorize]: module "auth_log" returns ok for request 10
modcall[authorize]: module "chap" returns noop for request 10
modcall[authorize]: module "mschap" returns noop for request 10
rlm_eap: Request is supposed to be proxied to Realm NULL. Not doing EAP.
modcall[authorize]: module "eap" returns noop for request 10
xmlrpcAuthorize called.
FRXmlRpcModule::authorize called.
FRXmlRpcModule::authorize vpUsername found.
Proxying is turned on.
modcall[authorize]: module "xmlrpc" returns noop for request 10
modcall: group authorize returns updated for request 10
Processing the pre-proxy section of radiusd.conf
modcall: entering group pre-proxy for request 10
radius_xlat: '/var/log/radius//pre-proxy-detail-20040707'
rlm_detail: /var/log/radius/%{Client-IP-Address}/pre-proxy-detail-%Y%m%d expands to
/var/log/radius//pre-proxy-detail-20040707
modcall[pre-proxy]: module "pre_proxy_log" returns ok for request 10
modcall: group pre-proxy returns ok for request 10
Sending Access-Request of id 4 to 192.168.10.43:1812
Framed-MTU = 1466
NAS-IP-Address = 192.168.10.113
NAS-Identifier = "D-link Corp. Access Point"
User-Name = "user_1"
Service-Type = Framed-User
NAS-Port = 65
NAS-Port-Type = Wireless-802.11
NAS-Port-Id = "ether2_65"
Called-Station-Id = "00-05-5d-99-5f-3a"
Calling-Station-Id = "00-30-65-24-4c-5b"
Connect-Info = "CONNECT Ethernet 0Mbps Full duplex"
State = 0xbffaa2e18c3fe0a78e5183ee7aee01ac
EAP-Message =
0x0203006619800000005c160301005701000053030140ec8baa55d9dce47661e05d6f5d2789eb9c12a381fe48eacd30a88ffca482dd00002c00050004000aff830009ff82000300080006ff8000010016001500140013001200110018001b001a001700190100
Message-Authenticator = 0x00000000000000000000000000000000
Proxy-State = 0x313636
Thread 1 waiting to be assigned a request
rad_recv: Access-Request packet from host 192.168.10.113:1026, id=166, length=310
Ignoring duplicate packet from client DLink-7000AP:1026 - ID: 166, due to outstanding
proxied request 10.
--- Walking the entire request list ---
Cleaning up request 9 ID 165 with timestamp 40ec8b7d
Re-sending Access-Request of id 4 to 192.168.10.43:1812
Framed-MTU = 1466
NAS-IP-Address = 192.168.10.113
NAS-Identifier = "D-link Corp. Access Point"
User-Name = "user_1"
Service-Type = Framed-User
NAS-Port = 65
NAS-Port-Type = Wireless-802.11
NAS-Port-Id = "ether2_65"
Called-Station-Id = "00-05-5d-99-5f-3a"
Calling-Station-Id = "00-30-65-24-4c-5b"
Connect-Info = "CONNECT Ethernet 0Mbps Full duplex"
State = 0xbffaa2e18c3fe0a78e5183ee7aee01ac
EAP-Message =
0x0203006619800000005c160301005701000053030140ec8baa55d9dce47661e05d6f5d2789eb9c12a381fe48eacd30a88ffca482dd00002c00050004000aff830009ff82000300080006ff8000010016001500140013001200110018001b001a001700190100
Message-Authenticator = 0x00000000000000000000000000000000
Realm = "NULL"
EAP-Type = PEAP
Realm = "NULL"
Proxy-State = 0x313636
Waking up in 5 seconds...
rad_recv: Access-Reject packet from host 192.168.10.43:1812, id=4, length=25
Waking up in 5 seconds...
Thread 2 got semaphore
Thread 2 handling request 10, (5 handled so far)
Proxy-State = 0x313636
Processing the post-proxy section of radiusd.conf
modcall: entering group post-proxy for request 10
radius_xlat: '/var/log/radius//post-proxy-detail-20040707'
rlm_detail: /var/log/radius/%{Client-IP-Address}/post-proxy-detail-%Y%m%d expands to
/var/log/radius//post-proxy-detail-20040707
modcall[post-proxy]: module "post_proxy_log" returns ok for request 10
modcall[post-proxy]: module "eap" returns noop for request 10
FRXmlRpcModule::postProxy called.
FRXmlRpcModule::logonStatus vpUsername not found. Using request->userName.
FRXmlRpcModule::logonStatus Proxying is turned on. Local Auth is off.
FRXmlRpcModule::logonStatus Called-Station-ID found.
FRXmlRpcModule::sendLogOnFailure userLogonFail successful.
modcall[post-proxy]: module "xmlrpc" returns noop for request 10
modcall: group post-proxy returns ok for request 10
Login incorrect (Home Server says so): [user_1/<no User-Password attribute>] (from
client DLink-7000AP port 65 cli 00-30-65-24-4c-5b)
Delaying request 10 for 1 seconds
Finished request 10
Going to the next request
Thread 2 waiting to be assigned a request
--- Walking the entire request list ---
Sending Access-Reject of id 166 to 192.168.10.113:1026
Waking up in 1 seconds...
--- Walking the entire request list ---
Cleaning up request 10 ID 166 with timestamp 40ec8b87
Nothing to do. Sleeping until we see a request.
