Some help in Freeradius - debug

[tnt at kalik.net]

>this is the debug for user jvidal and the user didn`t found ....
>
>rad_recv: Access-Request packet from host 192.168.0.2:1035, id=100,
>length=154
>        User-Name = "jvidal"
>        NAS-IP-Address = 192.168.0.2
>        NAS-Port = 3
>        Called-Station-Id = "00-1E-2A-3C-D2-90:NETGEAR2"
>        Calling-Station-Id = "00-18-4D-66-60-24"
>        Framed-MTU = 1400
>        NAS-Port-Type = Wireless-802.11
>        Connect-Info = "CONNECT 54Mbps 802.11g"
>        EAP-Message = 0x0200000b016a766964616c
>        Message-Authenticator = 0xd245baabd1d9b6ece4c2122fe0b744df
>  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
>  modcall[authorize]: module "mschap" returns noop for request 0
>    rlm_realm: No '@' in User-Name = "jvidal", looking up realm NULL
>    rlm_realm: No such realm "NULL"
>  modcall[authorize]: module "suffix" returns noop for request 0
>  rlm_eap: EAP packet type response id 0 length 11
>  rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
>  modcall[authorize]: module "eap" returns updated for request 0
>radius_xlat:  'jvidal'
>rlm_sql (sql): sql_set_user escaped user --> 'jvidal'
>radius_xlat:  'SELECT id, UserName, Attribute, Value, op           FROM
>radcheck           WHERE Username = 'jvidal'          ORDER BY id'
>rlm_sql (sql): Reservingrlm_sql_mysql: query:  SELECT id, UserName,
>Attribute, Value, op           FROM radcheck           WHERE Username =
>'jvidal'          ORDER BY id
>radius_xlat:  'SELECT
>radgroupcheck.id,radgroupcheck.GroupName,radgroupcheck.Attribute,radgroupcheck.Value,radgroupcheck.op  FROM radgroupcheck,usergroup WHERE usergroup.Username = 'jvidal' AND usergroup.GroupName = radgroupcheck.GroupName ORDER BY radgroupcheck.id'
>rlm_sql_mysql: query:  SELECT
>radgroupcheck.id,radgroupcheck.GroupName,radgroupcheck.Attribute,radgroupcheck.Value,radgroupcheck.op  FROM radgroupcheck,usergroup WHERE usergroup.Username = 'jvidal' AND usergroup.GroupName = radgroupcheck.GroupName ORDER BY radgroupcheck.id
>radius_xlat:  'SELECT id, UserName, Attribute, Value, op           FROM
>radreply           WHERE Username = 'jvidal'           ORDER BY id'
>rlm_sql_mysql: query:  SELECT id, UserName, Attribute, Value, op
>FROM radreply           WHERE Username = 'jvidal'           ORDER BY id
>radius_xlat:  'SELECT
>radgroupreply.id,radgroupreply.GroupName,radgroupreply.Attribute,radgroupreply.Value,radgroupreply.op  FROM radgroupreply,usergroup WHERE usergroup.Username = 'jvidal' AND usergroup.GroupName = radgroupreply.GroupName ORDER BY radgroupreply.id'
>rlm_sql_mysql: query:  SELECT
>radgroupreply.id,radgroupreply.GroupName,radgroupreply.Attribute,radgroupreply.Value,radgroupreply.op  FROM radgroupreply,usergroup WHERE usergroup.Username = 'jvidal' AND usergroup.GroupName = radgroupreply.GroupName ORDER BY radgroupreply.id
>rlm_sql (sql): Released sql socket id: 4
>rlm_sql (sql): No matching entry in the database for request from user
>[jvidal]
>  modcall[authorize]: module "sql" returns notfound for request 0
>modcall: leaving 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 tls
>  rlm_eap_tls: Initiate
>  rlm_eap_tls: Start returned 1
>  modcall[authenticate]: module "eap" returns handled for request 0
> sql socket id: 4
>rlm_sql (sql): No matching entry in the database for request from user
>[jvidal]
>  modcall[authorize]: module "sql" returns notfound for request 0
>modcall: leaving 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 tls
>  rlm_eap_tls: Initiate
>  rlm_eap_tls: Start returned 1
>  modcall[authenticate]: module "eap" returns handled for request 0
>modcall: leaving group authenticate (returns handled) for request 0
>Sending Access-Challenge of id 100 to 192.168.0.2 port 1035
>        EAP-Message = 0x010100061920
>        Message-Authenticator = 0x00000000000000000000000000000000
>        State = 0x314214bdd05f8421ec27027c7fade7d4
>Finished request 0
>Going to the next request
>--- Walking the entire request list ---
>Waking up in 6 seconds...
>

This debug (that's a problem with certificates explained in FAQ and
eap.conf) doesn't belong to this radius.log output:

>> >But radius.log is reporting this:
>> >
>> >Tue Dec 23 10:40:44 2008 : Info: rlm_eap_mschapv2: Issuing Challenge
>> >Tue Dec 23 10:40:44 2008 : Info: rlm_sql (sql): No matching entry in the
>> >database for request from user [jvidal]
>> >Tue Dec 23 10:40:44 2008 : Info: rlm_sql (sql): No matching entry in the
>> >database for request from user [jvidal]
>> >Tue Dec 23 10:40:44 2008 : Auth: Login incorrect: [jvidal/<no
>> >User-Password attribute>] (from client radius-server port 0)
>> >Tue Dec 23 10:40:44 2008 : Info: rlm_sql (sql): No matching entry in the
>> >database for request from user [jvidal]
>> >Tue Dec 23 10:40:44 2008 : Auth: Login incorrect: [jvidal/<no
>> >User-Password attribute>] (from client red-Wifi-FCMC1 port 1 cli
>> >00-18-4D-66-60-24)
>> >

Ivan Kalik
Kalik Informatika ISP