Problem with spaces in usernames.

29 Jan 2014

      My main goal is creating EAP-TLS configuration but I wanted to be sure
the easiest way is working fine. And it's not working for me.

What's wrong that 3.0.0 version doesn't treat:
"A Guest" the same way as aguest?
They are configured this way in users file:

"A Guest"       Cleartext-Password := "123456"
                Reply-Message = "Hello %{User-Name}"

aguest          Cleartext-Password := "123456"
                Reply-Message = "Hello, %{User-Name}"

and talking with radtest from other host makes following showing in debug:

rad_recv: Access-Request packet from host 10.0.6.10 port 57803, id=3,
length=77
        User-Name = 'A Guest'
        User-Password = '123456'
        NAS-IP-Address = 10.0.6.10
        NAS-Port = 0
        Message-Authenticator = 0x3499158ba2be438b4e63389ffd091332
Wed Jan 29 17:20:58 2014 : Debug: (0) # Executing section authorize from
file /usr/local/etc/raddb/sites-enabled/default
Wed Jan 29 17:20:58 2014 : Debug: (0)   authorize {
Wed Jan 29 17:20:58 2014 : Debug: (0)   filter_username filter_username {
Wed Jan 29 17:20:58 2014 : Debug: (0)    ? if (User-Name !=
"%{tolower:%{User-Name}}")
Wed Jan 29 17:20:58 2014 : Debug: %{tolower:%{User-Name}}
Wed Jan 29 17:20:58 2014 : Debug: Parsed xlat tree:
Wed Jan 29 17:20:58 2014 : Debug: xlat: tolower
Wed Jan 29 17:20:58 2014 : Debug: {
Wed Jan 29 17:20:58 2014 : Debug:       attribute: User-Name
Wed Jan 29 17:20:58 2014 : Debug:       {
Wed Jan 29 17:20:58 2014 : Debug:               ref  2
Wed Jan 29 17:20:58 2014 : Debug:               list 1
Wed Jan 29 17:20:58 2014 : Debug:               tag -128
Wed Jan 29 17:20:58 2014 : Debug:       }
Wed Jan 29 17:20:58 2014 : Debug: }
Wed Jan 29 17:20:58 2014 : Debug: (0)   expand:
"%{tolower:%{User-Name}}" -> 'a guest'
Wed Jan 29 17:20:58 2014 : Debug: (0)    ? if (User-Name !=
"%{tolower:%{User-Name}}")  -> TRUE
Wed Jan 29 17:20:58 2014 : Debug: (0)    if (User-Name !=
"%{tolower:%{User-Name}}")  {
Wed Jan 29 17:20:58 2014 : Debug: (0)   modsingle[authorize]: calling
reject (rlm_always) for request 0
Wed Jan 29 17:20:58 2014 : Debug: (0)   modsingle[authorize]: returned
from reject (rlm_always) for request 0
Wed Jan 29 17:20:58 2014 : Debug: (0)     [reject] = reject
Wed Jan 29 17:20:58 2014 : Debug: (0)    } # if (User-Name !=
"%{tolower:%{User-Name}}")  = reject
Wed Jan 29 17:20:58 2014 : Debug: (0)   } # filter_username
filter_username = reject
Wed Jan 29 17:20:58 2014 : Debug: (0)  } #  authorize = reject
Wed Jan 29 17:20:58 2014 : Debug: (0) Using Post-Auth-Type Reject
Wed Jan 29 17:20:58 2014 : Debug: (0) # Executing group from file
/usr/local/etc/raddb/sites-enabled/default
Wed Jan 29 17:20:58 2014 : Debug: (0)  Post-Auth-Type REJECT {
Wed Jan 29 17:20:58 2014 : Debug: (0)   modsingle[post-auth]: calling
attr_filter.access_reject (rlm_attr_filter) for request 0
Wed Jan 29 17:20:58 2014 : Debug: %{User-Name}
Wed Jan 29 17:20:58 2014 : Debug: Parsed xlat tree:
Wed Jan 29 17:20:58 2014 : Debug: attribute: User-Name
Wed Jan 29 17:20:58 2014 : Debug: {
Wed Jan 29 17:20:58 2014 : Debug:       ref  2
Wed Jan 29 17:20:58 2014 : Debug:       list 1
Wed Jan 29 17:20:58 2014 : Debug:       tag -128
Wed Jan 29 17:20:58 2014 : Debug: }
Wed Jan 29 17:20:58 2014 : Debug: (0) attr_filter.access_reject :
expand: "%{User-Name}" -> 'A Guest'
Wed Jan 29 17:20:58 2014 : Debug: (0) attr_filter.access_reject :
Matched entry DEFAULT at line 11
Wed Jan 29 17:20:58 2014 : Debug: (0)   modsingle[post-auth]: returned
from attr_filter.access_reject (rlm_attr_filter) for request 0
Wed Jan 29 17:20:58 2014 : Debug: (0)   [attr_filter.access_reject] =
updated
Wed Jan 29 17:20:58 2014 : Debug: (0)   modsingle[post-auth]: calling
eap (rlm_eap) for request 0
Wed Jan 29 17:20:58 2014 : Debug: (0) eap : Request didn't contain an
EAP-Message, not inserting EAP-Failure
Wed Jan 29 17:20:58 2014 : Debug: (0)   modsingle[post-auth]: returned
from eap (rlm_eap) for request 0
Wed Jan 29 17:20:58 2014 : Debug: (0)   [eap] = noop
Wed Jan 29 17:20:58 2014 : Debug: (0)   remove_reply_message_if_eap
remove_reply_message_if_eap {
Wed Jan 29 17:20:58 2014 : Debug: (0)    ? if (reply:EAP-Message &&
reply:Reply-Message)
Wed Jan 29 17:20:58 2014 : Debug: (0)    ? if (reply:EAP-Message &&
reply:Reply-Message)  -> FALSE
Wed Jan 29 17:20:58 2014 : Debug: (0)    else else {
Wed Jan 29 17:20:58 2014 : Debug: (0)   modsingle[post-auth]: calling
noop (rlm_always) for request 0
Wed Jan 29 17:20:58 2014 : Debug: (0)   modsingle[post-auth]: returned
from noop (rlm_always) for request 0
Wed Jan 29 17:20:58 2014 : Debug: (0)     [noop] = noop
Wed Jan 29 17:20:58 2014 : Debug: (0)    } # else else = noop
Wed Jan 29 17:20:58 2014 : Debug: (0)   } # remove_reply_message_if_eap
remove_reply_message_if_eap = noop
Wed Jan 29 17:20:58 2014 : Debug: (0)  } # Post-Auth-Type REJECT = updated
Wed Jan 29 17:20:58 2014 : Debug: (0) Finished request 0.
Wed Jan 29 17:20:58 2014 : Debug: Waking up in 0.3 seconds.
Wed Jan 29 17:20:58 2014 : Debug: Waking up in 0.6 seconds.
Wed Jan 29 17:20:59 2014 : Debug: (0) Sending delayed reject
Sending Access-Reject of id 3 from 10.0.6.207 port 1812 to 10.0.6.10
port 57803
Wed Jan 29 17:20:59 2014 : Debug: Waking up in 4.9 seconds.
Wed Jan 29 17:21:04 2014 : Debug: (0) Cleaning up request packet ID 3
with timestamp +29
Wed Jan 29 17:21:04 2014 : Info: Ready to process requests.
rad_recv: Access-Request packet from host 10.0.6.10 port 44948, id=210,
length=76
        User-Name = 'aguest'
        User-Password = '123456'
        NAS-IP-Address = 10.0.6.10
        NAS-Port = 0
        Message-Authenticator = 0xdfd5232531e2f84735f3a9b1b94c22c9
Wed Jan 29 17:21:10 2014 : Debug: (1) # Executing section authorize from
file /usr/local/etc/raddb/sites-enabled/default
Wed Jan 29 17:21:10 2014 : Debug: (1)   authorize {
Wed Jan 29 17:21:10 2014 : Debug: (1)   filter_username filter_username {
Wed Jan 29 17:21:10 2014 : Debug: (1)    ? if (User-Name !=
"%{tolower:%{User-Name}}")
Wed Jan 29 17:21:10 2014 : Debug: %{tolower:%{User-Name}}
Wed Jan 29 17:21:10 2014 : Debug: Parsed xlat tree:
Wed Jan 29 17:21:10 2014 : Debug: xlat: tolower
Wed Jan 29 17:21:10 2014 : Debug: {
Wed Jan 29 17:21:10 2014 : Debug:       attribute: User-Name
Wed Jan 29 17:21:10 2014 : Debug:       {
Wed Jan 29 17:21:10 2014 : Debug:               ref  2
Wed Jan 29 17:21:10 2014 : Debug:               list 1
Wed Jan 29 17:21:10 2014 : Debug:               tag -128
Wed Jan 29 17:21:10 2014 : Debug:       }
Wed Jan 29 17:21:10 2014 : Debug: }
Wed Jan 29 17:21:10 2014 : Debug: }
Wed Jan 29 17:21:10 2014 : Debug: (1)   expand:
"%{tolower:%{User-Name}}" -> 'aguest'
Wed Jan 29 17:21:10 2014 : Debug: (1)    ? if (User-Name !=
"%{tolower:%{User-Name}}")  -> FALSE
Wed Jan 29 17:21:10 2014 : Debug: (1)    ? if (User-Name =~ / /)
Wed Jan 29 17:21:10 2014 : Debug: (1)    ? if (User-Name =~ / /)  -> FALSE
Wed Jan 29 17:21:10 2014 : Debug: (1)    ? if (User-Name =~ /@.*@/ )
Wed Jan 29 17:21:10 2014 : Debug: (1)    ? if (User-Name =~ /@.*@/ )  ->
FALSE
Wed Jan 29 17:21:10 2014 : Debug: (1)    ? if (User-Name =~ /\\.\\./ )
Wed Jan 29 17:21:10 2014 : Debug: (1)    ? if (User-Name =~ /\\.\\./ )
-> FALSE
Wed Jan 29 17:21:10 2014 : Debug: (1)    ? if ((User-Name =~ /@/) &&
(User-Name !~ /@(.+)\\.(.+)$/)) Wed Jan 29 17:21:10 2014 : Debug: (1)
 ? if ((User-Name =~ /@/) &&
(User-Name !~ /@(.+)\\.(.+)$/))   -> FALSE
Wed Jan 29 17:21:10 2014 : Debug: (1)    ? if (User-Name =~ /\\.$/) Wed
Jan 29 17:21:10 2014 : Debug: (1)    ? if (User-Name =~ /\\.$/)   ->
FALSE
Wed Jan 29 17:21:10 2014 : Debug: (1)    ? if (User-Name =~ /@\\./) Wed
Jan 29 17:21:10 2014 : Debug: (1)    ? if (User-Name =~ /@\\./)   ->
FALSE
Wed Jan 29 17:21:10 2014 : Debug: (1)   } # filter_username
filter_username = notfound
Wed Jan 29 17:21:10 2014 : Debug: (1)   modsingle[authorize]: calling
preprocess (rlm_preprocess) for request 1
Wed Jan 29 17:21:10 2014 : Debug: (1)   modsingle[authorize]: returned
from preprocess (rlm_preprocess) for request 1
Wed Jan 29 17:21:10 2014 : Debug: (1)   [preprocess] = ok
Wed Jan 29 17:21:10 2014 : Debug: (1)   modsingle[authorize]: calling
chap (rlm_chap) for request 1
Wed Jan 29 17:21:10 2014 : Debug: (1)   modsingle[authorize]: returned
from chap (rlm_chap) for request 1
Wed Jan 29 17:21:10 2014 : Debug: (1)   [chap] = noop
Wed Jan 29 17:21:10 2014 : Debug: (1)   modsingle[authorize]: calling
mschap (rlm_mschap) for request 1
Wed Jan 29 17:21:10 2014 : Debug: (1)   modsingle[authorize]: returned
from mschap (rlm_mschap) for request 1
Wed Jan 29 17:21:10 2014 : Debug: (1)   [mschap] = noop
Wed Jan 29 17:21:10 2014 : Debug: (1)   modsingle[authorize]: calling
digest (rlm_digest) for request 1
Wed Jan 29 17:21:10 2014 : Debug: (1)   modsingle[authorize]: returned
from digest (rlm_digest) for request 1
Wed Jan 29 17:21:10 2014 : Debug: (1)   [digest] = noop
Wed Jan 29 17:21:10 2014 : Debug: (1)   modsingle[authorize]: calling
suffix (rlm_realm) for request 1
Wed Jan 29 17:21:10 2014 : Debug: (1) suffix : No '@' in User-Name =
"aguest", looking up realm NULL
Wed Jan 29 17:21:10 2014 : Debug: (1) suffix : No such realm "NULL"
Wed Jan 29 17:21:10 2014 : Debug: (1)   modsingle[authorize]: returned
from suffix (rlm_realm) for request 1
Wed Jan 29 17:21:10 2014 : Debug: (1)   [suffix] = noop
Wed Jan 29 17:21:10 2014 : Debug: (1)   modsingle[authorize]: calling
eap (rlm_eap) for request 1
Wed Jan 29 17:21:10 2014 : Debug: (1) eap : No EAP-Message, not doing EAP
Wed Jan 29 17:21:10 2014 : Debug: (1)   modsingle[authorize]: returned
from eap (rlm_eap) for request 1
Wed Jan 29 17:21:10 2014 : Debug: (1)   [eap] = noop
Wed Jan 29 17:21:10 2014 : Debug: (1)   modsingle[authorize]: calling
files (rlm_files) for request 1
Wed Jan 29 17:21:10 2014 : Debug: (1) files : users: Matched entry
aguest at line 57
Wed Jan 29 17:21:10 2014 : Debug: Hello, %{User-Name}
Wed Jan 29 17:21:10 2014 : Debug: Parsed xlat tree:
Wed Jan 29 17:21:10 2014 : Debug: literal: 'Hello, '
Wed Jan 29 17:21:10 2014 : Debug: attribute: User-Name
Wed Jan 29 17:21:10 2014 : Debug: {
Wed Jan 29 17:21:10 2014 : Debug:       ref  2
Wed Jan 29 17:21:10 2014 : Debug:       list 1
Wed Jan 29 17:21:10 2014 : Debug:       tag -128
Wed Jan 29 17:21:10 2014 : Debug: }
Wed Jan 29 17:21:10 2014 : Debug: (1) files :   expand: "Hello,
%{User-Name}" -> 'Hello, aguest'
Wed Jan 29 17:21:10 2014 : Debug: (1)   modsingle[authorize]: returned
from files (rlm_files) for request 1
Wed Jan 29 17:21:10 2014 : Debug: (1)   [files] = ok
Wed Jan 29 17:21:10 2014 : Debug: (1)   modsingle[authorize]: calling
expiration (rlm_expiration) for request 1
Wed Jan 29 17:21:10 2014 : Debug: (1)   modsingle[authorize]: returned
from expiration (rlm_expiration) for request 1
Wed Jan 29 17:21:10 2014 : Debug: (1)   [expiration] = noop
Wed Jan 29 17:21:10 2014 : Debug: (1)   modsingle[authorize]: calling
logintime (rlm_logintime) for request 1
Wed Jan 29 17:21:10 2014 : Debug: (1)   modsingle[authorize]: returned
from logintime (rlm_logintime) for request 1
Wed Jan 29 17:21:10 2014 : Debug: (1)   [logintime] = noop
Wed Jan 29 17:21:10 2014 : Debug: (1)   modsingle[authorize]: calling
pap (rlm_pap) for request 1
Wed Jan 29 17:21:10 2014 : Debug: (1)   modsingle[authorize]: returned
from pap (rlm_pap) for request 1
Wed Jan 29 17:21:10 2014 : Debug: (1)   [pap] = updated
Wed Jan 29 17:21:10 2014 : Debug: (1)  } #  authorize = updated
Wed Jan 29 17:21:10 2014 : Debug: (1) Found Auth-Type = PAP
Wed Jan 29 17:21:10 2014 : Debug: (1) # Executing group from file
/usr/local/etc/raddb/sites-enabled/default
Wed Jan 29 17:21:10 2014 : Debug: (1)  Auth-Type PAP {
Wed Jan 29 17:21:10 2014 : Debug: (1)   modsingle[authenticate]: calling
pap (rlm_pap) for request 1
Wed Jan 29 17:21:10 2014 : Debug: (1) pap : login attempt with password
"123456"
Wed Jan 29 17:21:10 2014 : Debug: (1) pap : Using clear text password
"123456"
Wed Jan 29 17:21:10 2014 : Debug: (1) pap : User authenticated successfully
Wed Jan 29 17:21:10 2014 : Debug: (1)   modsingle[authenticate]:
returned from pap (rlm_pap) for request 1
Wed Jan 29 17:21:10 2014 : Debug: (1)   [pap] = ok
Wed Jan 29 17:21:10 2014 : Debug: (1)  } # Auth-Type PAP = ok
Wed Jan 29 17:21:10 2014 : Debug: (1) # Executing section post-auth from
file /usr/local/etc/raddb/sites-enabled/default
Wed Jan 29 17:21:10 2014 : Debug: (1)   post-auth {
Wed Jan 29 17:21:10 2014 : Debug: (1)   modsingle[post-auth]: calling
exec (rlm_exec) for request 1
Wed Jan 29 17:21:10 2014 : Debug: (1)   modsingle[post-auth]: returned
from exec (rlm_exec) for request 1
Wed Jan 29 17:21:10 2014 : Debug: (1)   [exec] = noop
Wed Jan 29 17:21:10 2014 : Debug: (1)   remove_reply_message_if_eap
remove_reply_message_if_eap {
Wed Jan 29 17:21:10 2014 : Debug: (1)    ? if (reply:EAP-Message &&
reply:Reply-Message)
Wed Jan 29 17:21:10 2014 : Debug: (1)    ? if (reply:EAP-Message &&
reply:Reply-Message)  -> FALSE
Wed Jan 29 17:21:10 2014 : Debug: (1)    else else {
Wed Jan 29 17:21:10 2014 : Debug: (1)   modsingle[post-auth]: calling
noop (rlm_always) for request 1
Wed Jan 29 17:21:10 2014 : Debug: (1)   modsingle[post-auth]: returned
from noop (rlm_always) for request 1
Wed Jan 29 17:21:10 2014 : Debug: (1)     [noop] = noop
Wed Jan 29 17:21:10 2014 : Debug: (1)    } # else else = noop
Wed Jan 29 17:21:10 2014 : Debug: (1)   } # remove_reply_message_if_eap
remove_reply_message_if_eap = noop
Wed Jan 29 17:21:10 2014 : Debug: (1)  } #  post-auth = noop
Sending Access-Accept of id 210 from 10.0.6.207 port 1812 to 10.0.6.10
port 44948
        Reply-Message = 'Hello, aguest'
Wed Jan 29 17:21:10 2014 : Debug: (1) Finished request 1.
Wed Jan 29 17:21:10 2014 : Debug: Waking up in 0.3 seconds.
Wed Jan 29 17:21:10 2014 : Debug: Waking up in 4.6 seconds.

-- 
Pozdrawiam,
Maciej Milewski