Message-Authenticator and Proxy
Xavier
xavee2004 at yahoo.fr
Sun Aug 7 20:16:11 CEST 2005
Hi All.
We are experiencing a problem with our Radius proxy server which is running
FreeRADIUS 1.0.2 :
When FR poxies the request, it resets the Message-Authenticator attribute to
zero in a Access-Request packet.
therefore the radius server (third party) answers sometimes Accept and
sometimes reject. We suppose that this server is buggy or does not support
the Message-Authenticator attribute.
I looked in the RFCs but none discuss about Message-Authenticator and proxy.
I suppose the proxy should re-calculate the Message-Authenticator and
rewrite it to the forwarded packet, but this is not the case of FreeRADIUS.
In order to solve this problem I need to know if FreeRADIUS has the good
behaviour.
I tried also to suppress the Message-Authenticator attribute with the
attr_rewrite module, but I didn't manage to.
Below is the debug output of FreeRADIUS :
Accepted Request :
rad_recv: Access-Request packet from host 132.113.29.88:13165, id=211,
length=181 Acct-Session-Id = "73a67d36"
NAS-Port = 1
NAS-Port-Type = Wireless-802.11
User-Name = "JOHN at wifi"
Calling-Station-Id = "00-0C-F1-38-14-AA"
Called-Station-Id = "00-03-52-01-8E-25"
Framed-IP-Address = 10.0.0.10
User-Password = "mypass"
NAS-Identifier = "COLUBRIS"
NAS-IP-Address = 192.168.1.250
Framed-MTU = 1496
Connect-Info = "HTTPS"
Service-Type = Framed-User
Message-Authenticator = 0x63f6f96ba2bf5891c93e86ba3438422c
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 "chap" returns noop for request 12
modcall[authorize]: module "mschap" returns noop for request 12
rlm_realm: Looking up realm "wifi" for User-Name = "JOHN at wifi"
rlm_realm: Found realm "wifi"
rlm_realm: Proxying request from user JOHN to realm wifi
rlm_realm: Adding Realm = "wifi"
rlm_realm: Preparing to proxy authentication request to realm "wifi"
modcall[authorize]: module "suffix" returns updated for request 12
modcall[authorize]: module "degrade" returns notfound for request 12
users: Matched entry DEFAULT at line 152
users: Matched entry DEFAULT at line 171
modcall[authorize]: module "tempacc" returns ok for request 12
modcall: group authorize returns updated for request 12
Sending Access-Request of id 11 to 192.168.2.23:1812
Acct-Session-Id = "73a67d36"
NAS-Port = 1
NAS-Port-Type = Wireless-802.11
User-Name = "JOHN at wifi"
Calling-Station-Id = "00-0C-F1-38-14-AA"
Called-Station-Id = "00-03-52-01-8E-25"
Framed-IP-Address = 10.0.0.10
User-Password = "mypass"
NAS-Identifier = "COLUBRIS"
NAS-IP-Address = 192.168.1.250
Framed-MTU = 1496
Connect-Info = "HTTPS"
Service-Type = Framed-User
Message-Authenticator = 0x00000000000000000000000000000000
Proxy-State = 0x323131
--- Walking the entire request list ---
Waking up in 1 seconds...
rad_recv: Access-Accept packet from host 192.168.2.23:1812, id=11, length=49
Session-Timeout = 35666
Service-Type = Framed-User
Framed-IP-Netmask = 255.255.255.0
Framed-IP-Address = 255.255.255.254
Proxy-State = 0x323131
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 "chap" returns noop for request 12
modcall[authorize]: module "mschap" returns noop for request 12
rlm_realm: Proxy reply, or no User-Name. Ignoring.
modcall[authorize]: module "suffix" returns noop for request 12
modcall[authorize]: module "degrade" returns notfound for request 12
users: Matched entry DEFAULT at line 152
users: Matched entry DEFAULT at line 171
modcall[authorize]: module "tempacc" returns ok for request 12
modcall: group authorize returns ok for request 12
rad_check_password: Found Auth-Type
rad_check_password: Auth-Type = Accept, accepting the user
Login OK: [JOHN at wifi] (from client Nomadix port 1 cli 00-0C-F1-38-14-AA)
Processing the post-auth section of radiusd.conf
modcall: entering group post-auth for request 12
rlm_sql (sql): Processing sql_postauth
radius_xlat: 'JOHN at wifi'
rlm_sql (sql): sql_set_user escaped user --> 'JOHN at wifi'
radius_xlat: 'INSERT into radpostauth (id, user, pass, reply, date) values
('', 'JOHN at wifi', 'mypass', 'Access-Accept', NOW())'
rlm_sql (sql) in sql_postauth: query is INSERT into radpostauth (id, user,
pass, reply, date) values ('', 'JOHN at wifi', 'mypass', 'Access-Accept',
NOW())
rlm_sql (sql): Reserving sql socket id: 2
rlm_sql (sql): Released sql socket id: 2
modcall[post-auth]: module "sql" returns ok for request 12
modcall: group post-auth returns ok for request 12
Sending Access-Accept of id 211 to 132.113.29.88:13165
Session-Timeout = 35666
Service-Type = Framed-User
Framed-IP-Netmask = 255.255.255.0
Framed-IP-Address = 255.255.255.254
Framed-MTU = 576
Idle-Timeout = 60
Finished request 12
Going to the next request
Waking up in 1 seconds...
rad_recv: Accounting-Request packet from host 132.113.29.88:13165, id=0,
length=150
User-Name = "JOHN at wifi"
NAS-Port = 1
NAS-Port-Type = Wireless-802.11
NAS-Identifier = "COLUBRIS"
NAS-IP-Address = 192.168.1.250
Acct-Status-Type = Start
Calling-Station-Id = "00-0C-F1-38-14-AA"
Called-Station-Id = "00-03-52-01-8E-25"
Event-Timestamp = "Aug 5 2005 16:52:15 CEST"
Acct-Delay-Time = 0
Acct-Session-Id = "73a67d36"
Acct-Authentic = RADIUS
Framed-IP-Address = 10.0.0.10
Processing the preacct section of radiusd.conf
modcall: entering group preacct for request 13
modcall[preacct]: module "preprocess" returns noop for request 13
rlm_acct_unique: Hashing 'NAS-Port = 1,Client-IP-Address =
132.113.29.88,NAS-IP-Address = 192.168.1.250,Acct-Session-Id =
"73a67d36",User-Name = "JOHN at wifi"'
rlm_acct_unique: Acct-Unique-Session-ID = "876079519f963dc1".
modcall[preacct]: module "acct_unique" returns ok for request 13
rlm_realm: Looking up realm "wifi" for User-Name = "JOHN at wifi"
rlm_realm: Found realm "wifi"
rlm_realm: Proxying request from user JOHN to realm wifi
rlm_realm: Adding Realm = "wifi"
rlm_realm: Preparing to proxy accounting request to realm "wifi"
modcall[preacct]: module "suffix" returns updated for request 13
modcall: group preacct returns updated for request 13
Processing the accounting section of radiusd.conf
modcall: entering group accounting for request 13
radius_xlat: '/var/log/freeradius/radacct/132.113.29.88/detail-20050805'
rlm_detail: /var/log/freeradius/radacct/%{Client-IP-Address}/detail-%Y%m%d
expands to /var/log/freeradius/radacct/132.113.29.88/detail-20050805
rlm_detail: Freeradius-Proxied-To set to 192.168.2.23
modcall[accounting]: module "detail" returns ok for request 13
radius_xlat: 'JOHN at wifi'
rlm_sql (sql): sql_set_user escaped user --> 'JOHN at wifi'
radius_xlat: 'INSERT into radacct (AcctSessionId, AcctUniqueId, UserName,
Realm, NASIPAddress, NASPortId, NASPortType, AcctStartTime, AcctStopTime,
AcctSessionTime, AcctAuthentic, ConnectInfo_start, ConnectInfo_stop,
AcctInputOctets, AcctOutputOctets, CalledStationId, CallingStationId,
AcctTerminateCause, ServiceType, FramedProtocol, FramedIPAddress,
AcctStartDelay, AcctStopDelay) values('73a67d36', '876079519f963dc1',
'JOHN at wifi', 'wifi', '192.168.1.250', '1', 'Wireless-802.11', '2005-08-05
16:49:36', '0', '0', 'RADIUS', '', '', '0', '0', '00-03-52-01-8E-25',
'00-0C-F1-38-14-AA', '', '', '', '10.0.0.10', '0', '0')'
rlm_sql (sql): Reserving sql socket id: 1
rlm_sql (sql): Released sql socket id: 1
modcall[accounting]: module "sql" returns ok for request 13
radius_xlat: '/var/log/freeradius/radutmp'
radius_xlat: 'JOHN at wifi'
modcall[accounting]: module "radutmp" returns ok for request 13
modcall: group accounting returns ok for request 13
Sending Accounting-Request of id 1 to 192.168.2.23:1813
User-Name = "JOHN at wifi"
NAS-Port = 1
NAS-Port-Type = Wireless-802.11
NAS-Identifier = "COLUBRIS"
NAS-IP-Address = 192.168.1.250
Acct-Status-Type = Start
Calling-Station-Id = "00-0C-F1-38-14-AA"
Called-Station-Id = "00-03-52-01-8E-25"
Event-Timestamp = "Aug 5 2005 16:52:15 CEST"
Acct-Delay-Time = 0
Acct-Session-Id = "73a67d36"
Acct-Authentic = RADIUS
Framed-IP-Address = 10.0.0.10
Proxy-State = 0x30
Waking up in 1 seconds...
rad_recv: Accounting-Response packet from host 192.168.2.23:1813, id=1,
length=41
Service-Type = Framed-User
Framed-IP-Netmask = 255.255.255.0
Framed-IP-Address = 255.255.255.254
Proxy-State = 0x30
Sending Accounting-Response of id 0 to 132.113.29.88:13165
Finished request 13
Going to the next request
Waking up in 1 seconds...
--- Walking the entire request list ---
Waking up in 5 seconds...
rad_recv: Accounting-Request packet from host 132.113.29.88:13165, id=115,
length=198
User-Name = "JOHN at wifi"
NAS-Port = 1
NAS-Port-Type = Wireless-802.11
NAS-Identifier = "COLUBRIS"
NAS-IP-Address = 192.168.1.250
Acct-Status-Type = Stop
Calling-Station-Id = "00-0C-F1-38-14-AA"
Called-Station-Id = "00-03-52-01-8E-25"
Event-Timestamp = "Aug 5 2005 16:52:25 CEST"
Acct-Delay-Time = 0
Acct-Session-Id = "73a67d36"
Acct-Authentic = RADIUS
Acct-Session-Time = 11
Acct-Input-Octets = 5342
Acct-Input-Gigawords = 0
Acct-Input-Packets = 8
Acct-Output-Octets = 682
Acct-Output-Gigawords = 0
Acct-Output-Packets = 7
Acct-Terminate-Cause = User-Request
Framed-IP-Address = 10.0.0.10
Processing the preacct section of radiusd.conf
modcall: entering group preacct for request 14
modcall[preacct]: module "preprocess" returns noop for request 14
rlm_acct_unique: Hashing 'NAS-Port = 1,Client-IP-Address =
132.113.29.88,NAS-IP-Address = 192.168.1.250,Acct-Session-Id =
"73a67d36",User-Name = "JOHN at wifi"'
rlm_acct_unique: Acct-Unique-Session-ID = "876079519f963dc1".
modcall[preacct]: module "acct_unique" returns ok for request 14
rlm_realm: Looking up realm "wifi" for User-Name = "JOHN at wifi"
rlm_realm: Found realm "wifi"
rlm_realm: Proxying request from user JOHN to realm wifi
rlm_realm: Adding Realm = "wifi"
rlm_realm: Preparing to proxy accounting request to realm "wifi"
modcall[preacct]: module "suffix" returns updated for request 14
modcall: group preacct returns updated for request 14
Processing the accounting section of radiusd.conf
modcall: entering group accounting for request 14
radius_xlat: '/var/log/freeradius/radacct/132.113.29.88/detail-20050805'
rlm_detail: /var/log/freeradius/radacct/%{Client-IP-Address}/detail-%Y%m%d
expands to /var/log/freeradius/radacct/132.113.29.88/detail-20050805
rlm_detail: Freeradius-Proxied-To set to 192.168.2.23
modcall[accounting]: module "detail" returns ok for request 14
radius_xlat: 'JOHN at wifi'
rlm_sql (sql): sql_set_user escaped user --> 'JOHN at wifi'
radius_xlat: 'UPDATE radacct SET AcctStopTime = '2005-08-05 16:49:47',
AcctSessionTime = '11', AcctInputOctets = '5342', AcctOutputOctets = '682',
AcctTerminateCause = 'User-Request', AcctStopDelay = '0', ConnectInfo_stop =
'' WHERE AcctSessionId = '73a67d36' AND UserName = 'JOHN at wifi' AND
NASIPAddress = '192.168.1.250''
rlm_sql (sql): Reserving sql socket id: 0
rlm_sql (sql): Released sql socket id: 0
modcall[accounting]: module "sql" returns ok for request 14
radius_xlat: '/var/log/freeradius/radutmp'
radius_xlat: 'JOHN at wifi'
rlm_radutmp: Logout for NAS Nomadix port 1, but no Login record
modcall[accounting]: module "radutmp" returns ok for request 14
modcall: group accounting returns ok for request 14
Sending Accounting-Request of id 2 to 192.168.2.23:1813
User-Name = "JOHN at wifi"
NAS-Port = 1
NAS-Port-Type = Wireless-802.11
NAS-Identifier = "COLUBRIS"
NAS-IP-Address = 192.168.1.250
Acct-Status-Type = Stop
Calling-Station-Id = "00-0C-F1-38-14-AA"
Called-Station-Id = "00-03-52-01-8E-25"
Event-Timestamp = "Aug 5 2005 16:52:25 CEST"
Acct-Delay-Time = 0
Acct-Session-Id = "73a67d36"
Acct-Authentic = RADIUS
Acct-Session-Time = 11
Acct-Input-Octets = 5342
Acct-Input-Gigawords = 0
Acct-Input-Packets = 8
Acct-Output-Octets = 682
Acct-Output-Gigawords = 0
Acct-Output-Packets = 7
Acct-Terminate-Cause = User-Request
Framed-IP-Address = 10.0.0.10
Proxy-State = 0x313135
--- Walking the entire request list ---
Waking up in 1 seconds...
rad_recv: Accounting-Response packet from host 192.168.2.23:1813, id=2,
length=43
Service-Type = Framed-User
Framed-IP-Netmask = 255.255.255.0
Framed-IP-Address = 255.255.255.254
Proxy-State = 0x313135
Sending Accounting-Response of id 115 to 132.113.29.88:13165
Finished request 14
Going to the next request
Waking up in 1 seconds...
--- Walking the entire request list ---
Waking up in 5 seconds...
--- Walking the entire request list ---
Cleaning up request 14 ID 115 with timestamp 42f37c8b
Nothing to do.
Rejected request :
rad_recv: Access-Request packet from host 132.113.29.88:13165, id=1,
length=181
Acct-Session-Id = "41705ece"
NAS-Port = 1
NAS-Port-Type = Wireless-802.11
User-Name = "JOHN at wifi"
Calling-Station-Id = "00-0C-F1-38-14-AA"
Called-Station-Id = "00-03-52-01-8E-25"
Framed-IP-Address = 10.0.0.10
User-Password = "mypass"
NAS-Identifier = "COLUBRIS"
NAS-IP-Address = 192.168.1.250
Framed-MTU = 1496
Connect-Info = "HTTPS"
Service-Type = Framed-User
Message-Authenticator = 0x97c0f2889372bfd63d04904e75dde9c9
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 "chap" returns noop for request 15
modcall[authorize]: module "mschap" returns noop for request 15
rlm_realm: Looking up realm "wifi" for User-Name = "JOHN at wifi"
rlm_realm: Found realm "wifi"
rlm_realm: Proxying request from user JOHN to realm wifi
rlm_realm: Adding Realm = "wifi"
rlm_realm: Preparing to proxy authentication request to realm "wifi"
modcall[authorize]: module "suffix" returns updated for request 15
modcall[authorize]: module "degrade" returns notfound for request 15
users: Matched entry DEFAULT at line 152
users: Matched entry DEFAULT at line 171
modcall[authorize]: module "tempacc" returns ok for request 15
modcall: group authorize returns updated for request 15
Sending Access-Request of id 12 to 192.168.2.23:1812
Acct-Session-Id = "41705ece"
NAS-Port = 1
NAS-Port-Type = Wireless-802.11
User-Name = "JOHN at wifi"
Calling-Station-Id = "00-0C-F1-38-14-AA"
Called-Station-Id = "00-03-52-01-8E-25"
Framed-IP-Address = 10.0.0.10
User-Password = "mypass"
NAS-Identifier = "COLUBRIS"
NAS-IP-Address = 192.168.1.250
Framed-MTU = 1496
Connect-Info = "HTTPS"
Service-Type = Framed-User
Message-Authenticator = 0x00000000000000000000000000000000
Proxy-State = 0x31
--- Walking the entire request list ---
Waking up in 1 seconds...
rad_recv: Access-Reject packet from host 192.168.2.23:1812, id=12, length=41
Service-Type = Framed-User
Framed-IP-Netmask = 255.255.255.0
Framed-IP-Address = 255.255.255.254
Proxy-State = 0x31
Login incorrect (Home Server says so): [JOHN at wifi/mypass] (from client
Nomadix port 1 cli 00-0C-F1-38-14-AA)
Processing the post-auth section of radiusd.conf
modcall: entering group Post-Auth-Type for request 15
rlm_sql (sql): Processing sql_postauth
radius_xlat: 'JOHN at wifi'
rlm_sql (sql): sql_set_user escaped user --> 'JOHN at wifi'
radius_xlat: 'INSERT into radpostauth (id, user, pass, reply, date) values
('', 'JOHN at wifi', 'mypass', 'Access-Reject', NOW())'
rlm_sql (sql) in sql_postauth: query is INSERT into radpostauth (id, user,
pass, reply, date) values ('', 'JOHN at wifi', 'mypass', 'Access-Reject',
NOW())
rlm_sql (sql): Reserving sql socket id: 4
rlm_sql (sql): Released sql socket id: 4
modcall[post-auth]: module "sql" returns ok for request 15
modcall: group Post-Auth-Type returns ok for request 15
Delaying request 15 for 1 seconds
Finished request 15
Going to the next request
Waking up in 1 seconds...
--- Walking the entire request list ---
Waking up in 1 seconds...
--- Walking the entire request list ---
Sending Access-Reject of id 1 to 132.113.29.88:13165
Waking up in 4 seconds.
Regards,
Xavier.
More information about the Freeradius-Users
mailing list