EAP/TTLS with Windows SecureW2 -> symbol lookup error: rlm_eap_ttls-1.0.4.so:

Achim Friedland mailinglists at ahzf.de
Tue Sep 13 10:18:40 CEST 2005


Hello,


I have a strange error with freeradius eap/ttls...

I'm using CISCO AP1200 with a central WDS box. The main authentication 
is done by freeradius. Authentication for special users is by by another 
freeradius using the realm "zki"...

Using Secure W2 for authentication fails when the outer identity is set 
to default (== anonymous). SecureW2 seem to send "anonymous at zki" instead 
of the plain "anonymous". freeradius 1.0.4 will crash when receiving 
"anonymous at zki" as outer identity, complaining about: "radiusd: symbol 
lookup error: /usr/local/lib/rlm_eap_ttls-1.0.4.so:"

Setting the Outer Identity to "anonymous" by hand and everything seems 
to work fine... Using Mac OS X 10.4.x is also working fine...

Is this a freeradius bug or is this an configuration mistake?



thx...
achim




WindowsXP SecureW2 with Outer Identity default:
  "Use anonymous outer identity"
---------------------------------------

rad_recv: Access-Request packet from host 141.24.X.153:1814, id=2,
length=196
         User-Name = "anonymous at zki"
         Framed-MTU = 1400
         Called-Station-Id = "0012.d91d.8506"
         Calling-Station-Id = "0040.96a6.f325"
         Cisco-AVPair = "ssid=802.1X_A"
         Service-Type = Login-User
         Message-Authenticator = 0x5335216cd649ea7293d33d345ccaf001
         EAP-Message = 0x0203001201616e6f6e796d6f7573407a6b69
         NAS-Port-Type = Wireless-802.11
         Cisco-NAS-Port = "11152"
         NAS-Port = 11152
         State = 0xf32cdefb67a6c958841160d79940483d
         NAS-IP-Address = 141.24.Y.197
         NAS-Identifier = "wds"
         Proxy-State = 0x3130
   Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 0
   modcall[authorize]: module "preprocess" returns ok for request 0
   modcall[authorize]: module "chap" returns noop for request 0
     rlm_realm: Looking up realm "zki" for User-Name = "anonymous at zki"
     rlm_realm: Found realm "zki"
     rlm_realm: Adding Stripped-User-Name = "anonymous"
     rlm_realm: Proxying request from user anonymous to realm zki
     rlm_realm: Adding Realm = "zki"
     rlm_realm: Authentication realm is LOCAL.
   modcall[authorize]: module "suffix" returns noop for request 0
   rlm_eap: EAP packet type response id 3 length 18
   rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
   modcall[authorize]: module "eap" returns updated for request 0
   modcall[authorize]: module "files" returns notfound for request 0
radius_xlat:  'anonymous'
rlm_sql (sql): sql_set_user escaped user --> 'anonymous'
radius_xlat:  'SELECT id,UserName,Attribute,Value,op FROM radcheck WHERE
Username = 'anonymous' ORDER BY id'
rlm_sql (sql): Reserving sql socket id: 4
rlm_sql (sql): User anonymous not found in radcheck
radius_xlat:  'SELECT
radgroupcheck.id,radgroupcheck.GroupName,radgroupcheck.Attribute,radgroupcheck.Value,radgroupcheck.op
FROM radgroupcheck,usergroup WHERE usergroup.Username = 'anonymous' AND
usergroup.GroupName = radgroupcheck.GroupName ORDER BY radgroupcheck.id'
radius_xlat:  'SELECT
radgroupreply.id,radgroupreply.GroupName,radgroupreply.Attribute,radgroupreply.Value,radgroupreply.op
FROM radgroupreply,usergroup WHERE usergroup.Username = 'anonymous' AND
usergroup.GroupName = radgroupreply.GroupName ORDER BY radgroupreply.id'
rlm_sql (sql): User anonymous not found in radgroupcheck
rlm_sql (sql): User not found
rlm_sql (sql): Released sql socket id: 4
   modcall[authorize]: module "sql" returns notfound for request 0
modcall: group authorize returns updated for request 0
   rad_check_password:  Found Auth-Type EAP
auth: type "EAP"
   Processing the authenticate section of radiusd.conf
modcall: entering group authenticate for request 0
   rlm_eap: EAP Identity
   rlm_eap: processing type md5
rlm_eap_md5: Issuing Challenge
   modcall[authenticate]: module "eap" returns handled for request 0
modcall: group authenticate returns handled for request 0
Sending Access-Challenge of id 2 to 141.24.X.153:1814
         EAP-Message = 0x01040016041077a0fb8bd58d97d0b17ac1df9de98f47
         Message-Authenticator = 0x00000000000000000000000000000000
         State = 0x36f0b37fa9b38cb7bbb80bdf4fe46ed3
         Proxy-State = 0x3130
Finished request 0
Going to the next request
--- Walking the entire request list ---
Waking up in 6 seconds...
rad_recv: Access-Request packet from host 141.24.X.153:1814, id=3,
length=184
         User-Name = "anonymous at zki"
         Framed-MTU = 1400
         Called-Station-Id = "0012.d91d.8506"
         Calling-Station-Id = "0040.96a6.f325"
         Cisco-AVPair = "ssid=802.1X_A"
         Service-Type = Login-User
         Message-Authenticator = 0xcadb1594ff0bdba3568742d74f111ea9
         EAP-Message = 0x020400060315
         NAS-Port-Type = Wireless-802.11
         Cisco-NAS-Port = "11152"
         NAS-Port = 11152
         State = 0x36f0b37fa9b38cb7bbb80bdf4fe46ed3
         NAS-IP-Address = 141.24.Y.197
         NAS-Identifier = "wds"
         Proxy-State = 0x3131
   Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 1
   modcall[authorize]: module "preprocess" returns ok for request 1
   modcall[authorize]: module "chap" returns noop for request 1
     rlm_realm: Looking up realm "zki" for User-Name = "anonymous at zki"
     rlm_realm: Found realm "zki"
     rlm_realm: Adding Stripped-User-Name = "anonymous"
     rlm_realm: Proxying request from user anonymous to realm zki
     rlm_realm: Adding Realm = "zki"
     rlm_realm: Authentication realm is LOCAL.
   modcall[authorize]: module "suffix" returns noop for request 1
   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 1
   modcall[authorize]: module "files" returns notfound for request 1
radius_xlat:  'anonymous'
rlm_sql (sql): sql_set_user escaped user --> 'anonymous'
radius_xlat:  'SELECT id,UserName,Attribute,Value,op FROM radcheck WHERE
Username = 'anonymous' ORDER BY id'
rlm_sql (sql): Reserving sql socket id: 3
rlm_sql (sql): User anonymous not found in radcheck
radius_xlat:  'SELECT
radgroupcheck.id,radgroupcheck.GroupName,radgroupcheck.Attribute,radgroupcheck.Value,radgroupcheck.op
FROM radgroupcheck,usergroup WHERE usergroup.Username = 'anonymous' AND
usergroup.GroupName = radgroupcheck.GroupName ORDER BY radgroupcheck.id'
radius_xlat:  'SELECT
radgroupreply.id,radgroupreply.GroupName,radgroupreply.Attribute,radgroupreply.Value,radgroupreply.op
FROM radgroupreply,usergroup WHERE usergroup.Username = 'anonymous' AND
usergroup.GroupName = radgroupreply.GroupName ORDER BY radgroupreply.id'
rlm_sql (sql): User anonymous not found in radgroupcheck
rlm_sql (sql): User not found
rlm_sql (sql): Released sql socket id: 3
   modcall[authorize]: module "sql" returns notfound for request 1
modcall: group authorize returns updated for request 1
   rad_check_password:  Found Auth-Type EAP
auth: type "EAP"
   Processing the authenticate section of radiusd.conf
modcall: entering group authenticate for request 1
   rlm_eap: Request found, released from the list
   rlm_eap: EAP NAK
  rlm_eap: EAP-NAK asked for EAP-Type/ttls
   rlm_eap: processing type tls
   rlm_eap_tls: Initiate
   rlm_eap_tls: Start returned 1
   modcall[authenticate]: module "eap" returns handled for request 1
modcall: group authenticate returns handled for request 1
Sending Access-Challenge of id 3 to 141.24.X.153:1814
         EAP-Message = 0x010500061520
         Message-Authenticator = 0x00000000000000000000000000000000
         State = 0x2b311532eebabb9eb8503c79a2d4fa9a
         Proxy-State = 0x3131
Finished request 1
Going to the next request
Waking up in 6 seconds...
rad_recv: Access-Request packet from host 141.24.X.153:1814, id=4,
length=238
         User-Name = "anonymous at zki"
         Framed-MTU = 1400
         Called-Station-Id = "0012.d91d.8506"
         Calling-Station-Id = "0040.96a6.f325"
         Cisco-AVPair = "ssid=802.1X_A"
         Service-Type = Login-User
         Message-Authenticator = 0xdfbeb7f6c68f0044d69f70e8c7789c49
         EAP-Message =
0x0205003c158000000032160301002d01000029030168032500510bcf65fcee8021c8e22ed0192f5f8033a7007c36fdf4e5904e86
         NAS-Port-Type = Wireless-802.11
         Cisco-NAS-Port = "11152"
         NAS-Port = 11152
         State = 0x2b311532eebabb9eb8503c79a2d4fa9a
         NAS-IP-Address = 141.24.Y.197
         NAS-Identifier = "wds"
         Proxy-State = 0x3132
   Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 2
   modcall[authorize]: module "preprocess" returns ok for request 2
   modcall[authorize]: module "chap" returns noop for request 2
     rlm_realm: Looking up realm "zki" for User-Name = "anonymous at zki"
     rlm_realm: Found realm "zki"
     rlm_realm: Adding Stripped-User-Name = "anonymous"
     rlm_realm: Proxying request from user anonymous to realm zki
     rlm_realm: Adding Realm = "zki"
     rlm_realm: Authentication realm is LOCAL.
   modcall[authorize]: module "suffix" returns noop for request 2
   rlm_eap: EAP packet type response id 5 length 60
   rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
   modcall[authorize]: module "eap" returns updated for request 2
   modcall[authorize]: module "files" returns notfound for request 2
radius_xlat:  'anonymous'
rlm_sql (sql): sql_set_user escaped user --> 'anonymous'
radius_xlat:  'SELECT id,UserName,Attribute,Value,op FROM radcheck WHERE
Username = 'anonymous' ORDER BY id'
rlm_sql (sql): Reserving sql socket id: 2
rlm_sql (sql): User anonymous not found in radcheck
radius_xlat:  'SELECT
radgroupcheck.id,radgroupcheck.GroupName,radgroupcheck.Attribute,radgroupcheck.Value,radgroupcheck.op
FROM radgroupcheck,usergroup WHERE usergroup.Username = 'anonymous' AND
usergroup.GroupName = radgroupcheck.GroupName ORDER BY radgroupcheck.id'
radius_xlat:  'SELECT
radgroupreply.id,radgroupreply.GroupName,radgroupreply.Attribute,radgroupreply.Value,radgroupreply.op
FROM radgroupreply,usergroup WHERE usergroup.Username = 'anonymous' AND
usergroup.GroupName = radgroupreply.GroupName ORDER BY radgroupreply.id'
rlm_sql (sql): User anonymous not found in radgroupcheck
rlm_sql (sql): User not found
radiusd-windosen-bug 
                  Ctrl-K H for help
rlm_sql (sql): Released sql socket id: 2
   modcall[authorize]: module "sql" returns notfound for request 2
modcall: group authorize returns updated for request 2
   rad_check_password:  Found Auth-Type EAP
auth: type "EAP"
   Processing the authenticate section of radiusd.conf
modcall: entering group authenticate for request 2
   rlm_eap: Request found, released from the list
   rlm_eap: EAP/ttls
   rlm_eap: processing type ttls
   rlm_eap_ttls: Authenticate
radiusd: symbol lookup error: /usr/local/lib/rlm_eap_ttls-1.0.4.so:
undefined symbol: eaptls_process





WindowsXP SecureW2 with Outer Identity:
"Specify outer Identity: 'anonymous'"
---------------------------------------

rad_recv: Access-Request packet from host 141.24.X.153:1814, id=14,
length=65
         User-Name = "rznotebook at zki"
         User-Password = "notenbuch"
         NAS-IP-Address = 127.0.0.1
         Proxy-State = 0x313534
   Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 0
   modcall[authorize]: module "preprocess" returns ok for request 0
   modcall[authorize]: module "chap" returns noop for request 0
     rlm_realm: Looking up realm "zki" for User-Name = "rznotebook at zki"
     rlm_realm: Found realm "zki"
     rlm_realm: Adding Stripped-User-Name = "rznotebook"
     rlm_realm: Proxying request from user rznotebook to realm zki
     rlm_realm: Adding Realm = "zki"
     rlm_realm: Authentication realm is LOCAL.
   modcall[authorize]: module "suffix" returns noop for request 0
   rlm_eap: No EAP-Message, not doing EAP
   modcall[authorize]: module "eap" returns noop for request 0
   modcall[authorize]: module "files" returns notfound for request 0
radius_xlat:  'rznotebook'
rlm_sql (sql): sql_set_user escaped user --> 'rznotebook'
radius_xlat:  'SELECT id,UserName,Attribute,Value,op FROM radcheck WHERE
Username = 'rznotebook' ORDER BY id'
rlm_sql (sql): Reserving sql socket id: 4
radius_xlat:  'SELECT
radgroupcheck.id,radgroupcheck.GroupName,radgroupcheck.Attribute,radgroupcheck.Value,radgroupcheck.op
FROM radgroupcheck,usergroup WHERE usergroup.Username = 'rznotebook' AND
usergroup.GroupName = radgroupcheck.GroupName ORDER BY radgroupcheck.id'
radius_xlat:  'SELECT id,UserName,Attribute,Value,op FROM radreply WHERE
Username = 'rznotebook' ORDER BY id'
radius_xlat:  'SELECT
radgroupreply.id,radgroupreply.GroupName,radgroupreply.Attribute,radgroupreply.Value,radgroupreply.op
FROM radgroupreply,usergroup WHERE usergroup.Username = 'rznotebook' AND
usergroup.GroupName = radgroupreply.GroupName ORDER BY radgroupreply.id'
rlm_sql (sql): Released sql socket id: 4
   modcall[authorize]: module "sql" returns ok for request 0
modcall: group authorize returns ok for request 0
auth: type Local
auth: user supplied User-Password matches local User-Password
radiusd-windosen-bug 
                  Ctrl-K H for help
Login OK: [rznotebook at zki] (from client telly-rz port 0)
   Processing the post-auth section of radiusd.conf
modcall: entering group post-auth for request 0
rlm_sql (sql): Processing sql_postauth
radius_xlat:  'rznotebook'
rlm_sql (sql): sql_set_user escaped user --> 'rznotebook'
radius_xlat:  'INSERT into radpostauth (id, user, pass, reply, date) values
('', 'rznotebook at zki', 'notenbuch', 'Access-Accept', NOW())'
rlm_sql (sql) in sql_postauth: query is INSERT into radpostauth (id, user,
pass, reply, date) values ('', 'rznotebook at zki', 'notenbuch',
'Access-Accept', NOW())
rlm_sql (sql): Reserving sql socket id: 3
rlm_sql (sql): Released sql socket id: 3
   modcall[post-auth]: module "sql" returns ok for request 0
modcall: group post-auth returns ok for request 0
Sending Access-Accept of id 14 to 141.24.X.153:1814
         Proxy-State = 0x313534
Finished request 0
Going to the next request
--- Walking the entire request list ---
Waking up in 6 seconds...
--- Walking the entire request list ---
Cleaning up request 0 ID 14 with timestamp 4326761a
Nothing to do.  Sleeping until we see a request.





Mac OS X 10.4
-------------

rad_recv: Access-Request packet from host 141.24.X.153:1814, id=15,
length=67
         User-Name = "fempowerbook at zki"
         User-Password = "fpb"
         NAS-IP-Address = 127.0.0.1
         Proxy-State = 0x313931
   Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 0
   modcall[authorize]: module "preprocess" returns ok for request 0
   modcall[authorize]: module "chap" returns noop for request 0
     rlm_realm: Looking up realm "zki" for User-Name = "fempowerbook at zki"
     rlm_realm: Found realm "zki"
     rlm_realm: Adding Stripped-User-Name = "fempowerbook"
     rlm_realm: Proxying request from user fempowerbook to realm zki
     rlm_realm: Adding Realm = "zki"
     rlm_realm: Authentication realm is LOCAL.
   modcall[authorize]: module "suffix" returns noop for request 0
   rlm_eap: No EAP-Message, not doing EAP
   modcall[authorize]: module "eap" returns noop for request 0
   modcall[authorize]: module "files" returns notfound for request 0
radius_xlat:  'fempowerbook'
rlm_sql (sql): sql_set_user escaped user --> 'fempowerbook'
radius_xlat:  'SELECT id,UserName,Attribute,Value,op FROM radcheck WHERE
Username = 'fempowerbook' ORDER BY id'
rlm_sql (sql): Reserving sql socket id: 4
radius_xlat:  'SELECT
radgroupcheck.id,radgroupcheck.GroupName,radgroupcheck.Attribute,radgroupcheck.Value,radgroupcheck.op
FROM radgroupcheck,usergroup WHERE usergroup.Username = 'fempowerbook' AND
usergroup.GroupName = radgroupcheck.GroupName ORDER BY radgroupcheck.id'
radius_xlat:  'SELECT id,UserName,Attribute,Value,op FROM radreply WHERE
Username = 'fempowerbook' ORDER BY id'
radius_xlat:  'SELECT
radgroupreply.id,radgroupreply.GroupName,radgroupreply.Attribute,radgroupreply.Value,radgroupreply.op
FROM radgroupreply,usergroup WHERE usergroup.Username = 'fempowerbook' AND
usergroup.GroupName = radgroupreply.GroupName ORDER BY radgroupreply.id'
rlm_sql (sql): Released sql socket id: 4
   modcall[authorize]: module "sql" returns ok for request 0
modcall: group authorize returns ok for request 0
auth: type Local
auth: user supplied User-Password matches local User-Password
radiusd-windosen-bug 
                  Ctrl-K H for help
Login OK: [fempowerbook at zki] (from client telly-rz port 0)
   Processing the post-auth section of radiusd.conf
modcall: entering group post-auth for request 0
rlm_sql (sql): Processing sql_postauth
radius_xlat:  'fempowerbook'
rlm_sql (sql): sql_set_user escaped user --> 'fempowerbook'
radius_xlat:  'INSERT into radpostauth (id, user, pass, reply, date) values
('', 'fempowerbook at zki', 'fpb', 'Access-Accept', NOW())'
rlm_sql (sql) in sql_postauth: query is INSERT into radpostauth (id, user,
pass, reply, date) values ('', 'fempowerbook at zki', 'fpb',
'Access-Accept', NOW())
rlm_sql (sql): Reserving sql socket id: 3
rlm_sql (sql): Released sql socket id: 3
   modcall[post-auth]: module "sql" returns ok for request 0
modcall: group post-auth returns ok for request 0
Sending Access-Accept of id 15 to 141.24.X.153:1814
         Proxy-State = 0x313931
Finished request 0
Going to the next request
--- Walking the entire request list ---
Waking up in 6 seconds...
--- Walking the entire request list ---
Cleaning up request 0 ID 15 with timestamp 43267cb9
Nothing to do.  Sleeping until we see a request.






More information about the Freeradius-Users mailing list