rlm_checkval: Could not find item named Calling-Station-Id in request
Karim Bourenane
karim.bourenane at gmail.com
Tue Jul 18 09:21:40 CEST 2017
Hello
Thanks you for your reply.
My goal is to validate the user/password from the MAC addresss and IP
Adresse for several network name identified in the user Ldap account.
Here all information from the output.
*Here the command sended from the RadiusServer proxy (Centos )*:
radtest -x idtestradius2 testradius 127.0.0.1:1812 0 testing123
*Here the output from ProxyRadius, with command radiusd -Xxx*:
Received Access-Request Id 63 from 127.0.0.1:35361 to 127.0.0.1:1812 length
83
User-Name = 'idtestradius2'
User-Password = 'testradius'
NAS-IP-Address = 10.166.120.43
NAS-Port = 0
Message-Authenticator = 0x028425169cd1722c65277cb8c1f99ada
Tue Jul 18 09:07:08 2017 : Debug: (0) Received Access-Request packet from
host 127.0.0.1 port 35361, id=63, length=83
Tue Jul 18 09:07:08 2017 : Debug: (0) User-Name = 'idtestradius2'
Tue Jul 18 09:07:08 2017 : Debug: (0) User-Password = 'testradius'
Tue Jul 18 09:07:08 2017 : Debug: (0) NAS-IP-Address = 10.166.120.43
Tue Jul 18 09:07:08 2017 : Debug: (0) NAS-Port = 0
Tue Jul 18 09:07:08 2017 : Debug: (0) Message-Authenticator =
0x028425169cd1722c65277cb8c1f99ada
Tue Jul 18 09:07:08 2017 : Debug: (0) # Executing section authorize from
file /etc/raddb/sites-enabled/default
Tue Jul 18 09:07:08 2017 : Debug: (0) authorize {
Tue Jul 18 09:07:08 2017 : Debug: (0) filter_username filter_username {
Tue Jul 18 09:07:08 2017 : Debug: (0) if (!&User-Name)
Tue Jul 18 09:07:08 2017 : Debug: (0) if (!&User-Name) -> FALSE
Tue Jul 18 09:07:08 2017 : Debug: (0) if (&User-Name =~ / /)
Tue Jul 18 09:07:08 2017 : Debug: (0) if (&User-Name =~ / /) -> FALSE
Tue Jul 18 09:07:08 2017 : Debug: (0) if (&User-Name =~ /@.*@/ )
Tue Jul 18 09:07:08 2017 : Debug: (0) if (&User-Name =~ /@.*@/ ) ->
FALSE
Tue Jul 18 09:07:08 2017 : Debug: (0) if (&User-Name =~ /\\.\\./ )
Tue Jul 18 09:07:08 2017 : Debug: (0) if (&User-Name =~ /\\.\\./ ) ->
FALSE
Tue Jul 18 09:07:08 2017 : Debug: (0) if ((&User-Name =~ /@/) &&
(&User-Name !~ /@(.+)\\.(.+)$/))
Tue Jul 18 09:07:08 2017 : Debug: (0) if ((&User-Name =~ /@/) &&
(&User-Name !~ /@(.+)\\.(.+)$/)) -> FALSE
Tue Jul 18 09:07:08 2017 : Debug: (0) if (&User-Name =~ /\\.$/)
Tue Jul 18 09:07:08 2017 : Debug: (0) if (&User-Name =~ /\\.$/) ->
FALSE
Tue Jul 18 09:07:08 2017 : Debug: (0) if (&User-Name =~ /@\\./)
Tue Jul 18 09:07:08 2017 : Debug: (0) if (&User-Name =~ /@\\./) ->
FALSE
Tue Jul 18 09:07:08 2017 : Debug: (0) } # filter_username filter_username
= notfound
Tue Jul 18 09:07:08 2017 : Debug: (0) modsingle[authorize]: calling
preprocess (rlm_preprocess) for request 0
Tue Jul 18 09:07:08 2017 : Debug: ^(id.*)
Tue Jul 18 09:07:08 2017 : Debug: Parsed xlat tree:
Tue Jul 18 09:07:08 2017 : Debug: literal --> ^(id.*)
Tue Jul 18 09:07:08 2017 : Debug: (0) preprocess : EXPAND ^(id.*)
Tue Jul 18 09:07:08 2017 : Debug: (0) preprocess : --> ^(id.*)
Tue Jul 18 09:07:08 2017 : Debug: (0) preprocess : %{0}: Inserting new
value "idtestradius2"
Tue Jul 18 09:07:08 2017 : Debug: (0) preprocess : %{1}: Inserting new
value "idtestradius2"
Tue Jul 18 09:07:08 2017 : Debug: (0) preprocess : %{2}: Was empty
Tue Jul 18 09:07:08 2017 : Debug: (0) preprocess : %{3}: Was empty
Tue Jul 18 09:07:08 2017 : Debug: (0) preprocess : %{4}: Was empty
Tue Jul 18 09:07:08 2017 : Debug: (0) preprocess : %{5}: Was empty
Tue Jul 18 09:07:08 2017 : Debug: (0) preprocess : %{6}: Was empty
Tue Jul 18 09:07:08 2017 : Debug: (0) preprocess : %{7}: Was empty
Tue Jul 18 09:07:08 2017 : Debug: (0) preprocess : %{8}: Was empty
Tue Jul 18 09:07:08 2017 : Debug: (0) preprocess : hints: Matched DEFAULT
at 56
Tue Jul 18 09:07:08 2017 : Debug: (0) preprocess : ::: FROM 1 TO 6 MAX 7
Tue Jul 18 09:07:08 2017 : Debug: (0) preprocess : ::: Examining User-Name
Tue Jul 18 09:07:08 2017 : Debug: %{1}@CUSTOMER1
Tue Jul 18 09:07:08 2017 : Debug: Parsed xlat tree:
Tue Jul 18 09:07:08 2017 : Debug: regex-var --> 1
Tue Jul 18 09:07:08 2017 : Debug: literal --> @CUSTOMER1
Tue Jul 18 09:07:08 2017 : Debug: (0) preprocess : EXPAND %{1}@CUSTOMER1
Tue Jul 18 09:07:08 2017 : Debug: (0) preprocess : -->
idtestradius2 at CUSTOMER1
Tue Jul 18 09:07:08 2017 : Debug: (0) preprocess : ::: OVERWRITING
User-Name FROM 0 TO 0
Tue Jul 18 09:07:08 2017 : Debug: (0) preprocess : ::: TO in 6 out 6
Tue Jul 18 09:07:08 2017 : Debug: (0) preprocess : ::: to[0] = User-Name
Tue Jul 18 09:07:08 2017 : Debug: (0) preprocess : ::: to[1] =
User-Password
Tue Jul 18 09:07:08 2017 : Debug: (0) preprocess : ::: to[2] =
NAS-IP-Address
Tue Jul 18 09:07:08 2017 : Debug: (0) preprocess : ::: to[3] = NAS-Port
Tue Jul 18 09:07:08 2017 : Debug: (0) preprocess : ::: to[4] =
Message-Authenticator
Tue Jul 18 09:07:08 2017 : Debug: (0) preprocess : ::: to[5] =
Event-Timestamp
Tue Jul 18 09:07:08 2017 : Debug: (0) modsingle[authorize]: returned from
preprocess (rlm_preprocess) for request 0
Tue Jul 18 09:07:08 2017 : Debug: (0) [preprocess] = ok
Tue Jul 18 09:07:08 2017 : Debug: (0) modsingle[authorize]: calling chap
(rlm_chap) for request 0
Tue Jul 18 09:07:08 2017 : Debug: (0) modsingle[authorize]: returned from
chap (rlm_chap) for request 0
Tue Jul 18 09:07:08 2017 : Debug: (0) [chap] = noop
Tue Jul 18 09:07:08 2017 : Debug: (0) modsingle[authorize]: calling mschap
(rlm_mschap) for request 0
Tue Jul 18 09:07:08 2017 : Debug: (0) modsingle[authorize]: returned from
mschap (rlm_mschap) for request 0
Tue Jul 18 09:07:08 2017 : Debug: (0) [mschap] = noop
Tue Jul 18 09:07:08 2017 : Debug: (0) modsingle[authorize]: calling digest
(rlm_digest) for request 0
Tue Jul 18 09:07:08 2017 : Debug: (0) modsingle[authorize]: returned from
digest (rlm_digest) for request 0
Tue Jul 18 09:07:08 2017 : Debug: (0) [digest] = noop
Tue Jul 18 09:07:08 2017 : Debug: (0) modsingle[authorize]: calling suffix
(rlm_realm) for request 0
Tue Jul 18 09:07:08 2017 : Debug: (0) suffix : Checking for suffix after
"@"
Tue Jul 18 09:07:08 2017 : Debug: (0) suffix : Looking up realm
"CUSTOMER1" for User-Name = "idtestradius2 at CUSTOMER1"
Tue Jul 18 09:07:08 2017 : Debug: (0) suffix : Found realm "CUSTOMER1"
Tue Jul 18 09:07:08 2017 : Debug: (0) suffix : Adding Realm = "CUSTOMER1"
Tue Jul 18 09:07:08 2017 : Debug: (0) suffix : Proxying request from user
idtestradius2 at CUSTOMER1to realm CUSTOMER1
Tue Jul 18 09:07:08 2017 : Debug: (0) suffix : Preparing to proxy
authentication request to realm "PROXIMUS"
Tue Jul 18 09:07:08 2017 : Debug: (0) modsingle[authorize]: returned from
suffix (rlm_realm) for request 0
Tue Jul 18 09:07:08 2017 : Debug: (0) [suffix] = updated
Tue Jul 18 09:07:08 2017 : Debug: (0) modsingle[authorize]: calling eap
(rlm_eap) for request 0
Tue Jul 18 09:07:08 2017 : Debug: (0) eap : No EAP-Message, not doing EAP
Tue Jul 18 09:07:08 2017 : Debug: (0) modsingle[authorize]: returned from
eap (rlm_eap) for request 0
Tue Jul 18 09:07:08 2017 : Debug: (0) [eap] = noop
Tue Jul 18 09:07:08 2017 : Debug: (0) modsingle[authorize]: calling
expiration (rlm_expiration) for request 0
Tue Jul 18 09:07:08 2017 : Debug: (0) modsingle[authorize]: returned from
expiration (rlm_expiration) for request 0
Tue Jul 18 09:07:08 2017 : Debug: (0) [expiration] = noop
Tue Jul 18 09:07:08 2017 : Debug: (0) modsingle[authorize]: calling
logintime (rlm_logintime) for request 0
Tue Jul 18 09:07:08 2017 : Debug: (0) modsingle[authorize]: returned from
logintime (rlm_logintime) for request 0
Tue Jul 18 09:07:08 2017 : Debug: (0) [logintime] = noop
Tue Jul 18 09:07:08 2017 : Debug: (0) modsingle[authorize]: calling pap
(rlm_pap) for request 0
Tue Jul 18 09:07:08 2017 : Debug: (0) modsingle[authorize]: returned from
pap (rlm_pap) for request 0
Tue Jul 18 09:07:08 2017 : Debug: (0) [pap] = noop
Tue Jul 18 09:07:08 2017 : Debug: (0) } # authorize = updated
Tue Jul 18 09:07:08 2017 : Debug: (0) Empty pre-proxy section. Using
default return values.
Tue Jul 18 09:07:08 2017 : Debug: (0) proxy: Trying to allocate ID (0/2)
Tue Jul 18 09:07:08 2017 : Debug: (0) proxy: Failed allocating ID: Failed
finding socket, caller must allocate a new one
Tue Jul 18 09:07:08 2017 : Debug: (0) proxy: Trying to open a new listener
to the home server
Tue Jul 18 09:07:08 2017 : Debug: Opening new proxy socket 'proxy address
10.166.120.43 port 0'
Tue Jul 18 09:07:08 2017 : Debug: Listening on proxy address 10.166.120.43
port 38694
Tue Jul 18 09:07:08 2017 : Debug: (0) proxy: Trying to allocate ID (1/2)
Tue Jul 18 09:07:08 2017 : Debug: (0) proxy: request is now in proxy hash
Tue Jul 18 09:07:08 2017 : Debug: (0) proxy: allocating destination
10.166.120.133 port 1812 - Id 96
Tue Jul 18 09:07:08 2017 : Debug: (0) Proxying request to home server
10.166.120.133 port 1812 timeout 20.000000
Tue Jul 18 09:07:08 2017 : Debug: (0) Sending Access-Request packet to host
10.166.120.133 port 1812, id=96, length=0
Tue Jul 18 09:07:08 2017 : Debug: (0) User-Name = 'idtestradius2 at CUSTOMER1
'
Tue Jul 18 09:07:08 2017 : Debug: (0) User-Password = 'testradius'
Tue Jul 18 09:07:08 2017 : Debug: (0) NAS-IP-Address = 10.166.120.43
Tue Jul 18 09:07:08 2017 : Debug: (0) NAS-Port = 0
Tue Jul 18 09:07:08 2017 : Debug: (0) Message-Authenticator =
0x028425169cd1722c65277cb8c1f99ada
Tue Jul 18 09:07:08 2017 : Debug: (0) Event-Timestamp = 'Jul 18 2017
09:07:08 CEST'
Tue Jul 18 09:07:08 2017 : Debug: (0) Realm = 'CUSTOMER1'
Tue Jul 18 09:07:08 2017 : Debug: (0) Proxy-State = 0x3633
Sending Access-Request Id 96 from 10.166.120.43:38694 to 10.166.120.133:1812
User-Name = 'idtestradius2 at CUSTOMER1'
User-Password = 'testradius'
NAS-IP-Address = 10.166.120.43
NAS-Port = 0
Message-Authenticator = 0x028425169cd1722c65277cb8c1f99ada
Event-Timestamp = 'Jul 18 2017 09:07:08 CEST'
Proxy-State = 0x3633
Tue Jul 18 09:07:08 2017 : Debug: Waking up in 0.3 seconds.
Tue Jul 18 09:07:08 2017 : Debug: Waking up in 0.1 seconds.
Tue Jul 18 09:07:08 2017 : Debug: (0) Expecting proxy response no later
than 19.499718 seconds from now
Tue Jul 18 09:07:08 2017 : Debug: Waking up in 19.4 seconds.
Received Access-Reject Id 96 from 10.166.120.133:1812 to 10.166.120.43:38694
length 24
Proxy-State = 0x3633
Tue Jul 18 09:07:09 2017 : Debug: (0) Received Access-Reject packet from
host 10.166.120.133 port 1812, id=96, length=24
Tue Jul 18 09:07:09 2017 : Debug: (0) Proxy-State = 0x3633
Tue Jul 18 09:07:09 2017 : Debug: (0) proxy: request is no longer in proxy
hash
Tue Jul 18 09:07:09 2017 : Debug: (0) # Executing section post-proxy from
file /etc/raddb/sites-enabled/default
Tue Jul 18 09:07:09 2017 : Debug: (0) post-proxy {
Tue Jul 18 09:07:09 2017 : Debug: (0) modsingle[post-proxy]: calling eap
(rlm_eap) for request 0
Tue Jul 18 09:07:09 2017 : Debug: (0) eap : No pre-existing handler found
Tue Jul 18 09:07:09 2017 : Debug: (0) modsingle[post-proxy]: returned from
eap (rlm_eap) for request 0
Tue Jul 18 09:07:09 2017 : Debug: (0) [eap] = noop
Tue Jul 18 09:07:09 2017 : Debug: (0) } # post-proxy = noop
Tue Jul 18 09:07:09 2017 : Auth: (0) Login incorrect (Home Server says so):
[idtestradius2 at CUSTOMER1] (from client localhost port 0)
Tue Jul 18 09:07:09 2017 : Debug: (0) Using Post-Auth-Type Reject
Tue Jul 18 09:07:09 2017 : Debug: (0) # Executing group from file
/etc/raddb/sites-enabled/default
Tue Jul 18 09:07:09 2017 : Debug: (0) Post-Auth-Type REJECT {
Tue Jul 18 09:07:09 2017 : Debug: (0) modsingle[post-auth]: calling
attr_filter.access_reject (rlm_attr_filter) for request 0
Tue Jul 18 09:07:09 2017 : Debug: %{User-Name}
Tue Jul 18 09:07:09 2017 : Debug: Parsed xlat tree:
Tue Jul 18 09:07:09 2017 : Debug: attribute --> User-Name
Tue Jul 18 09:07:09 2017 : Debug: (0) attr_filter.access_reject : EXPAND
%{User-Name}
Tue Jul 18 09:07:09 2017 : Debug: (0) attr_filter.access_reject : -->
idtestradius2 at CUSTOMER1
Tue Jul 18 09:07:09 2017 : Debug: (0) attr_filter.access_reject : Matched
entry DEFAULT at line 11
Tue Jul 18 09:07:09 2017 : Debug: (0) modsingle[post-auth]: returned from
attr_filter.access_reject (rlm_attr_filter) for request 0
Tue Jul 18 09:07:09 2017 : Debug: (0) [attr_filter.access_reject] =
updated
Tue Jul 18 09:07:09 2017 : Debug: (0) modsingle[post-auth]: calling eap
(rlm_eap) for request 0
Tue Jul 18 09:07:09 2017 : Debug: (0) eap : Request didn't contain an
EAP-Message, not inserting EAP-Failure
Tue Jul 18 09:07:09 2017 : Debug: (0) modsingle[post-auth]: returned from
eap (rlm_eap) for request 0
Tue Jul 18 09:07:09 2017 : Debug: (0) [eap] = noop
Tue Jul 18 09:07:09 2017 : Debug: (0) remove_reply_message_if_eap
remove_reply_message_if_eap {
Tue Jul 18 09:07:09 2017 : Debug: (0) if (&reply:EAP-Message &&
&reply:Reply-Message)
Tue Jul 18 09:07:09 2017 : Debug: (0) if (&reply:EAP-Message &&
&reply:Reply-Message) -> FALSE
Tue Jul 18 09:07:09 2017 : Debug: (0) else else {
Tue Jul 18 09:07:09 2017 : Debug: (0) modsingle[post-auth]: calling noop
(rlm_always) for request 0
Tue Jul 18 09:07:09 2017 : Debug: (0) modsingle[post-auth]: returned from
noop (rlm_always) for request 0
Tue Jul 18 09:07:09 2017 : Debug: (0) [noop] = noop
Tue Jul 18 09:07:09 2017 : Debug: (0) } # else else = noop
Tue Jul 18 09:07:09 2017 : Debug: (0) } # remove_reply_message_if_eap
remove_reply_message_if_eap = noop
Tue Jul 18 09:07:09 2017 : Debug: (0) } # Post-Auth-Type REJECT = updated
Tue Jul 18 09:07:09 2017 : Debug: (0) Delaying response for 1 seconds
Tue Jul 18 09:07:09 2017 : Debug: Waking up in 0.3 seconds.
Tue Jul 18 09:07:09 2017 : Debug: Waking up in 0.6 seconds.
Tue Jul 18 09:07:10 2017 : Debug: (0) Sending delayed response
Tue Jul 18 09:07:10 2017 : Debug: (0) Sending Access-Reject packet to host
127.0.0.1 port 35361, id=63, length=0
Sending Access-Reject Id 63 from 127.0.0.1:1812 to 127.0.0.1:35361
Tue Jul 18 09:07:10 2017 : Debug: Waking up in 3.9 seconds.
Tue Jul 18 09:07:14 2017 : Debug: (0) Cleaning up request packet ID 63 with
timestamp +15
Tue Jul 18 09:07:14 2017 : Info: Ready to process requests
*And the output from the Radius Server Backend*:(plugged with the local
Ldap)
rad_recv: Access-Request packet from host 10.166.120.43 port 38694, id=96,
length=102
User-Name = "idtestradius2 at CUSTOMER1"
User-Password = "testradius"
NAS-IP-Address = 10.166.120.43
NAS-Port = 0
Message-Authenticator = 0xf0d7406bbd8e56ca8c40403578dbf4f0
Event-Timestamp = "Jul 18 2017 09:07:08 CEST"
Proxy-State = 0x3633
Tue Jul 18 09:07:08 2017 : Info: # Executing section authorize from file
/etc/raddb/sites-enabled/default
Tue Jul 18 09:07:08 2017 : Info: +group authorize {
Tue Jul 18 09:07:08 2017 : Info: ++[preprocess] = ok
Tue Jul 18 09:07:08 2017 : Info: ++[chap] = noop
Tue Jul 18 09:07:08 2017 : Info: ++[mschap] = noop
Tue Jul 18 09:07:08 2017 : Info: ++[digest] = noop
Tue Jul 18 09:07:08 2017 : Info: [suffix] Looking up realm "CUSTOMER1" for
User-Name = "idtestradius2 at CUSTOMER1"
Tue Jul 18 09:07:08 2017 : Info: [suffix] No such realm "CUSTOMER1"
Tue Jul 18 09:07:08 2017 : Info: ++[suffix] = noop
Tue Jul 18 09:07:08 2017 : Info: [eap] No EAP-Message, not doing EAP
Tue Jul 18 09:07:08 2017 : Info: ++[eap] = noop
Tue Jul 18 09:07:08 2017 : Info: [ldap] performing user authorization for
idtestradius2 at CUSTOMER1
Tue Jul 18 09:07:08 2017 : Info: [ldap] expand:
%{Stripped-User-Name} ->
Tue Jul 18 09:07:08 2017 : Info: [ldap] ... expanding second
conditional
Tue Jul 18 09:07:08 2017 : Info: [ldap] expand: %{User-Name} ->
idtestradius2 at CUSTOMER1
Tue Jul 18 09:07:08 2017 : Info: [ldap] expand:
(uid=%{%{Stripped-User-Name}:-%{User-Name}}) -> (uid=idtestradius2 at CUSTOMER1
)
Tue Jul 18 09:07:08 2017 : Info: [ldap] expand:
ou=Radius,dc=lab,dc=apt -> ou=Radius,dc=lab,dc=apt
Tue Jul 18 09:07:08 2017 : Debug: [ldap] ldap_get_conn: Checking Id: 0
Tue Jul 18 09:07:08 2017 : Debug: [ldap] ldap_get_conn: Got Id: 0
Tue Jul 18 09:07:08 2017 : Debug: [ldap] attempting LDAP reconnection
Tue Jul 18 09:07:08 2017 : Debug: [ldap] (re)connect to
ldapmaster.lab.rti:389, authentication 0
Tue Jul 18 09:07:08 2017 : Debug: [ldap] bind as
cn=tacacs,dc=lab,dc=apt/test123! to ldapmaster.lab.rti:389
Tue Jul 18 09:07:08 2017 : Debug: [ldap] waiting for bind result ...
Tue Jul 18 09:07:08 2017 : Debug: [ldap] Bind was successful
Tue Jul 18 09:07:08 2017 : Debug: [ldap] performing search in
ou=Radius,dc=lab,dc=apt, with filter (uid=idtestradius2 at CUSTOMER1)
Tue Jul 18 09:07:08 2017 : Info: [ldap] checking if remote access for
idtestradius2 at CUSTOMER1is allowed by dialupAccess
Tue Jul 18 09:07:08 2017 : Info: [ldap] Added User-Password = testradius in
check items
Tue Jul 18 09:07:08 2017 : Info: [ldap] looking for check items in
directory...
Tue Jul 18 09:07:08 2017 : Debug: [ldap] radiusNASIpAddress ->
NAS-IP-Address == 10.166.120.133
Tue Jul 18 09:07:08 2017 : Debug: [ldap] radiusExpiration -> Expiration
== "Aug 15 2018 00:00:00 CEST"
Tue Jul 18 09:07:08 2017 : Debug: [ldap] userPassword ->
Password-With-Header == "testradius"
Tue Jul 18 09:07:08 2017 : Debug: [ldap] radiusCallingStationId ->
Calling-Station-Id == "00-0C-29-BB-01-BC"
Tue Jul 18 09:07:08 2017 : Debug: [ldap] extracted attribute
Client-IP-Address from generic item Client-IP-Address = 10.166.120.43
Tue Jul 18 09:07:08 2017 : Info: [ldap] looking for reply items in
directory...
Tue Jul 18 09:07:08 2017 : Info: [ldap] user
idtestradius2 at CUSTOMER1authorized to use remote access
Tue Jul 18 09:07:08 2017 : Debug: [ldap] ldap_release_conn: Release Id: 0
Tue Jul 18 09:07:08 2017 : Info: ++[ldap] = ok
Tue Jul 18 09:07:08 2017 : Info: ++? if (!("%{control:Calling-Station-Id}")
)
Tue Jul 18 09:07:08 2017 : Info: expand:
%{control:Calling-Station-Id} -> 00-0C-29-BB-01-BC
Tue Jul 18 09:07:08 2017 : Info: ?? Evaluating
("%{control:Calling-Station-Id}") -> TRUE
Tue Jul 18 09:07:08 2017 : Info: ? Converting !TRUE -> FALSE
Tue Jul 18 09:07:08 2017 : Info: ++? if (!("%{control:Calling-Station-Id}")
) -> FALSE
Tue Jul 18 09:07:08 2017 : Info: ++? if (!("%{control:NAS-IP-Address}") )
Tue Jul 18 09:07:08 2017 : Info: expand: %{control:NAS-IP-Address}
-> 10.166.120.133
Tue Jul 18 09:07:08 2017 : Info: ?? Evaluating
("%{control:NAS-IP-Address}") -> TRUE
Tue Jul 18 09:07:08 2017 : Info: ? Converting !TRUE -> FALSE
Tue Jul 18 09:07:08 2017 : Info: ++? if (!("%{control:NAS-IP-Address}") )
-> FALSE
Tue Jul 18 09:07:08 2017 : Debug: rlm_checkval: Could not find item named
Calling-Station-Id in request
Tue Jul 18 09:07:08 2017 : Info: ++[checkval] = reject
Tue Jul 18 09:07:08 2017 : Info: +} # group authorize = reject
Tue Jul 18 09:07:08 2017 : Info: expand: Bad Pass -> Bad Pass
Tue Jul 18 09:07:08 2017 : Auth: Invalid user (rlm_checkval: Could not find
item named Calling-Station-Id in request): [idtestradius2 at CUSTOMER1/testradius]
(from client proxy-radius1 port 0) Bad Pass
Tue Jul 18 09:07:08 2017 : Info: Using Post-Auth-Type REJECT
Tue Jul 18 09:07:08 2017 : Info: # Executing group from file
/etc/raddb/sites-enabled/default
Tue Jul 18 09:07:08 2017 : Info: +group REJECT {
Tue Jul 18 09:07:08 2017 : Info: [attr_filter.access_reject] expand:
%{User-Name} -> idtestradius2 at CUSTOMER1
Tue Jul 18 09:07:08 2017 : Debug: attr_filter: Matched entry DEFAULT at
line 11
Tue Jul 18 09:07:08 2017 : Info: ++[attr_filter.access_reject] = updated
Tue Jul 18 09:07:08 2017 : Info: +} # group REJECT = updated
Tue Jul 18 09:07:08 2017 : Info: Delaying reject of request 0 for 1 seconds
Tue Jul 18 09:07:08 2017 : Debug: Going to the next request
Tue Jul 18 09:07:08 2017 : Debug: Waking up in 0.9 seconds.
Tue Jul 18 09:07:09 2017 : Info: Sending delayed reject for request 0
Sending Access-Reject of id 96 to 10.166.120.43 port 38694
Proxy-State = 0x3633
Tue Jul 18 09:07:09 2017 : Debug: Waking up in 4.9 seconds.
Tue Jul 18 09:07:14 2017 : Info: Cleaning up request 0 ID 96 with timestamp
+7
Tue Jul 18 09:07:14 2017 : Info: Ready to process requests.
Regards
2017-07-18 1:02 GMT+02:00 Cuong Nguyen <cuong.nguyenduy at gmail.com>:
> Can you run radius with debug (option -Xxx) and post the outout here?
>
> On Mon, 17 Jul 2017, 21:49 Karim Bourenane, <karim.bourenane at gmail.com>
> wrote:
>
> > Hello
> >
> > Im novice on Freeradius. I hope you can help me in my small problem.
> >
> > I want to install a new platform with in front the radius proxy server,
> and
> > in backend the Radius server with binding a local LDAP : Devices ->
> > RadiusProxy -> RadiusBackend -> OpenLdap.
> >
> > On the RadiusProxy the request was sent weel to the RadiusBackend. The
> > local Ldap binding running also weel, but he reject the user because he
> > dont find on the request ( proxy i believe) the Calling Station ID.
> >
> > Here my error on RadiusBackend :
> > Debug: rlm_checkval: Could not find item named Calling-Station-Id in
> > request
> >
> > The request sending by the proxy doesnt contain any info about this
> value :
> > Sending Access-Request Id 239 from 10.166.120.43:43997 to
> > 10.166.120.133:1812
> > User-Name = 'idtestradius2'
> > User-Password = 'testradius'
> > NAS-IP-Address = 10.166.120.43
> > NAS-Port = 0
> > Message-Authenticator = 0xfaf2b385fae53a0feb636c4940dc9f9e
> > Event-Timestamp = 'Jul 17 2017 14:38:42 CEST'
> > Proxy-State = 0x3235
> >
> > Can you help me please ?
> >
> > Regards
> >
> >
> >
> > --
> > Mr Karim Bourenane
> > +33686464439
> > -
> > List info/subscribe/unsubscribe? See
> > http://www.freeradius.org/list/users.html
> -
> List info/subscribe/unsubscribe? See http://www.freeradius.org/
> list/users.html
--
Mr Karim Bourenane
+33686464439
More information about the Freeradius-Users
mailing list