Freeradius with ldap authentication
Fatih Naufal
fatih.avila at gmail.com
Tue Jun 27 01:02:34 CEST 2017
Hello before i ask this question, i already read and try the freeradius +
ldap authentication from https://wiki.freeradius.org/protocol/LDAP and
http://confluence.diamond.ac.uk/display/PAAUTH/Using+LDAP+as+authentication+source.
But now i'm kinda stuck with that both documentation, because everytime i
test the user in ldap (using radtest) i get "no DN found". I already check
that the dn has properly set up (i'm using phpldapadmin to create user in
ldap to make it easier). Here is the debug log :
Tue Jun 27 05:54:40 2017 : Debug: (1) Received Access-Request Id 251 from
127.0.0.1:53093 to 127.0.0.1:1812 length 74
Tue Jun 27 05:54:41 2017 : Debug: (1) User-Name = "teke"
Tue Jun 27 05:54:41 2017 : Debug: (1) User-Password = "xxx"
Tue Jun 27 05:54:41 2017 : Debug: (1) NAS-IP-Address = 127.0.1.1
Tue Jun 27 05:54:41 2017 : Debug: (1) NAS-Port = 1812
Tue Jun 27 05:54:41 2017 : Debug: (1) Message-Authenticator =
0xef22ab207657169978bd2b65ef0f42c6
Tue Jun 27 05:54:41 2017 : Debug: (1) session-state: No State attribute
Tue Jun 27 05:54:41 2017 : Debug: (1) # Executing section authorize from
file /etc/freeradius/3.0/sites-enabled/default
Tue Jun 27 05:54:41 2017 : Debug: (1) authorize {
Tue Jun 27 05:54:41 2017 : Debug: (1) policy filter_username {
Tue Jun 27 05:54:41 2017 : Debug: (1) if (&User-Name) {
Tue Jun 27 05:54:41 2017 : Debug: (1) if (&User-Name) -> TRUE
Tue Jun 27 05:54:41 2017 : Debug: (1) if (&User-Name) {
Tue Jun 27 05:54:41 2017 : Debug: (1) if (&User-Name =~ /@[^@]*@/ )
{
Tue Jun 27 05:54:41 2017 : Debug: No matches
Tue Jun 27 05:54:41 2017 : Debug: (1) if (&User-Name =~ /@[^@]*@/ )
-> FALSE
Tue Jun 27 05:54:41 2017 : Debug: (1) if (&User-Name =~ /\.\./ ) {
Tue Jun 27 05:54:41 2017 : Debug: No matches
Tue Jun 27 05:54:41 2017 : Debug: (1) if (&User-Name =~ /\.\./ )
-> FALSE
Tue Jun 27 05:54:41 2017 : Debug: (1) if ((&User-Name =~ /@/) &&
(&User-Name !~ /@(.+)\.(.+)$/)) {
Tue Jun 27 05:54:41 2017 : Debug: No matches
Tue Jun 27 05:54:41 2017 : Debug: (1) if ((&User-Name =~ /@/) &&
(&User-Name !~ /@(.+)\.(.+)$/)) -> FALSE
Tue Jun 27 05:54:41 2017 : Debug: (1) if (&User-Name =~ /\.$/) {
Tue Jun 27 05:54:41 2017 : Debug: No matches
Tue Jun 27 05:54:41 2017 : Debug: (1) if (&User-Name =~ /\.$/) ->
FALSE
Tue Jun 27 05:54:41 2017 : Debug: (1) if (&User-Name =~ /@\./) {
Tue Jun 27 05:54:41 2017 : Debug: No matches
Tue Jun 27 05:54:41 2017 : Debug: (1) if (&User-Name =~ /@\./) ->
FALSE
Tue Jun 27 05:54:41 2017 : Debug: (1) } # if (&User-Name) = notfound
Tue Jun 27 05:54:41 2017 : Debug: (1) } # policy filter_username =
notfound
Tue Jun 27 05:54:41 2017 : Debug: (1) modsingle[authorize]: calling
preprocess (rlm_preprocess)
Tue Jun 27 05:54:41 2017 : Debug: (1) modsingle[authorize]: returned
from preprocess (rlm_preprocess)
Tue Jun 27 05:54:41 2017 : Debug: (1) [preprocess] = ok
Tue Jun 27 05:54:41 2017 : Debug: (1) modsingle[authorize]: calling
chap (rlm_chap)
Tue Jun 27 05:54:41 2017 : Debug: (1) modsingle[authorize]: returned
from chap (rlm_chap)
Tue Jun 27 05:54:41 2017 : Debug: (1) [chap] = noop
Tue Jun 27 05:54:41 2017 : Debug: (1) modsingle[authorize]: calling
mschap (rlm_mschap)
Tue Jun 27 05:54:41 2017 : Debug: (1) modsingle[authorize]: returned
from mschap (rlm_mschap)
Tue Jun 27 05:54:41 2017 : Debug: (1) [mschap] = noop
Tue Jun 27 05:54:41 2017 : Debug: (1) modsingle[authorize]: calling
digest (rlm_digest)
Tue Jun 27 05:54:41 2017 : Debug: (1) modsingle[authorize]: returned
from digest (rlm_digest)
Tue Jun 27 05:54:41 2017 : Debug: (1) [digest] = noop
Tue Jun 27 05:54:41 2017 : Debug: (1) modsingle[authorize]: calling
suffix (rlm_realm)
Tue Jun 27 05:54:41 2017 : Debug: (1) suffix: Checking for suffix after "@"
Tue Jun 27 05:54:41 2017 : Debug: (1) suffix: No '@' in User-Name = "teke",
looking up realm NULL
Tue Jun 27 05:54:41 2017 : Debug: (1) suffix: No such realm "NULL"
Tue Jun 27 05:54:41 2017 : Debug: (1) modsingle[authorize]: returned
from suffix (rlm_realm)
Tue Jun 27 05:54:41 2017 : Debug: (1) [suffix] = noop
Tue Jun 27 05:54:41 2017 : Debug: (1) modsingle[authorize]: calling eap
(rlm_eap)
Tue Jun 27 05:54:41 2017 : Debug: (1) eap: No EAP-Message, not doing EAP
Tue Jun 27 05:54:41 2017 : Debug: (1) modsingle[authorize]: returned
from eap (rlm_eap)
Tue Jun 27 05:54:41 2017 : Debug: (1) [eap] = noop
Tue Jun 27 05:54:41 2017 : Debug: (1) modsingle[authorize]: calling
files (rlm_files)
Tue Jun 27 05:54:41 2017 : Debug: (1) modsingle[authorize]: returned
from files (rlm_files)
Tue Jun 27 05:54:41 2017 : Debug: (1) [files] = noop
Tue Jun 27 05:54:41 2017 : Debug: (1) modsingle[authorize]: calling
ldap (rlm_ldap)
Tue Jun 27 05:54:41 2017 : Info: rlm_ldap (ldap): Closing connection (1):
Hit idle_timeout, was idle for 118721 seconds
Tue Jun 27 05:54:41 2017 : Debug: rlm_ldap: Closing libldap handle
0x558ba43988d0
Tue Jun 27 05:54:42 2017 : Info: rlm_ldap (ldap): Closing connection (2):
Hit idle_timeout, was idle for 118721 seconds
Tue Jun 27 05:54:42 2017 : Debug: rlm_ldap: Closing libldap handle
0x558ba439cf90
Tue Jun 27 05:54:42 2017 : Info: rlm_ldap (ldap): Closing connection (3):
Hit idle_timeout, was idle for 118721 seconds
Tue Jun 27 05:54:42 2017 : Debug: rlm_ldap: Closing libldap handle
0x558ba438f2e0
Tue Jun 27 05:54:42 2017 : Info: rlm_ldap (ldap): Closing connection (4):
Hit idle_timeout, was idle for 118721 seconds
Tue Jun 27 05:54:42 2017 : Debug: rlm_ldap (ldap): You probably need to
lower "min"
Tue Jun 27 05:54:42 2017 : Debug: rlm_ldap: Closing libldap handle
0x558ba4392d70
Tue Jun 27 05:54:42 2017 : Info: rlm_ldap (ldap): Closing connection (0):
Hit idle_timeout, was idle for 118711 seconds
Tue Jun 27 05:54:42 2017 : Debug: rlm_ldap (ldap): You probably need to
lower "min"
Tue Jun 27 05:54:42 2017 : Debug: rlm_ldap: Closing libldap handle
0x558ba44fefb0
Tue Jun 27 05:54:42 2017 : Info: rlm_ldap (ldap): Closing connection (5):
Hit idle_timeout, was idle for 118711 seconds
Tue Jun 27 05:54:42 2017 : Debug: rlm_ldap (ldap): You probably need to
lower "min"
Tue Jun 27 05:54:42 2017 : Debug: rlm_ldap: Closing libldap handle
0x558ba439f860
Tue Jun 27 05:54:42 2017 : Debug: rlm_ldap (ldap): 0 of 0 connections in
use. You may need to increase "spare"
Tue Jun 27 05:54:42 2017 : Info: rlm_ldap (ldap): Opening additional
connection (6), 1 of 32 pending slots used
Tue Jun 27 05:54:42 2017 : Debug: rlm_ldap (ldap): Connecting to
ldap://localhost:389
Tue Jun 27 05:54:42 2017 : Debug: rlm_ldap (ldap): New libldap handle
0x558ba438e620
Tue Jun 27 05:54:42 2017 : Debug: rlm_ldap (ldap): Waiting for bind
result...
Tue Jun 27 05:54:43 2017 : Debug: rlm_ldap (ldap): Bind successful
Tue Jun 27 05:54:43 2017 : Debug: rlm_ldap (ldap): Reserved connection (6)
Tue Jun 27 05:54:43 2017 : Debug: (1) ldap: EXPAND TMPL XLAT
Tue Jun 27 05:54:43 2017 : Debug:
(uid=%{%{Stripped-User-Name}:-%{User-Name}})
Tue Jun 27 05:54:43 2017 : Debug: Parsed xlat tree:
Tue Jun 27 05:54:43 2017 : Debug: literal --> (uid=
Tue Jun 27 05:54:43 2017 : Debug: if {
Tue Jun 27 05:54:43 2017 : Debug: attribute --> Stripped-User-Name
Tue Jun 27 05:54:43 2017 : Debug: }
Tue Jun 27 05:54:43 2017 : Debug: else {
Tue Jun 27 05:54:43 2017 : Debug: attribute --> User-Name
Tue Jun 27 05:54:43 2017 : Debug: }
Tue Jun 27 05:54:43 2017 : Debug: literal --> )
Tue Jun 27 05:54:43 2017 : Debug: (1) ldap: EXPAND
(uid=%{%{Stripped-User-Name}:-%{User-Name}})
Tue Jun 27 05:54:43 2017 : Debug: (1) ldap: --> (uid=teke)
Tue Jun 27 05:54:43 2017 : Debug: (1) ldap: EXPAND TMPL LITERAL
Tue Jun 27 05:54:43 2017 : Debug: (1) ldap: Performing search in "" with
filter "(uid=teke)", scope "sub"
Tue Jun 27 05:54:43 2017 : Debug: (1) ldap: Waiting for search result...
Tue Jun 27 05:54:43 2017 : Debug: (1) ldap: The specified DN wasn't found
Tue Jun 27 05:54:43 2017 : Debug: (1) ldap: Search returned no results
Tue Jun 27 05:54:43 2017 : Debug: rlm_ldap (ldap): Released connection (6)
Tue Jun 27 05:54:43 2017 : Info: rlm_ldap (ldap): Need 2 more connections
to reach 10 spares
Tue Jun 27 05:54:43 2017 : Info: rlm_ldap (ldap): Opening additional
connection (7), 1 of 31 pending slots used
Tue Jun 27 05:54:43 2017 : Debug: rlm_ldap (ldap): Connecting to
ldap://localhost:389
Tue Jun 27 05:54:43 2017 : Debug: rlm_ldap (ldap): New libldap handle
0x558ba439b660
Tue Jun 27 05:54:43 2017 : Debug: rlm_ldap (ldap): Waiting for bind
result...
Tue Jun 27 05:54:43 2017 : Debug: rlm_ldap (ldap): Bind successful
Tue Jun 27 05:54:43 2017 : Debug: (1) modsingle[authorize]: returned
from ldap (rlm_ldap)
Tue Jun 27 05:54:43 2017 : Debug: (1) [ldap] = notfound
Tue Jun 27 05:54:43 2017 : Debug: (1) } # authorize = notfound
Tue Jun 27 05:54:43 2017 : ERROR: (1) No Auth-Type found: rejecting the
user via Post-Auth-Type = Reject
Tue Jun 27 05:54:43 2017 : Debug: (1) Failed to authenticate the user
Tue Jun 27 05:54:43 2017 : Debug: (1) Using Post-Auth-Type Reject
Tue Jun 27 05:54:43 2017 : Debug: (1) # Executing group from file
/etc/freeradius/3.0/sites-enabled/default
Tue Jun 27 05:54:43 2017 : Debug: (1) Post-Auth-Type REJECT {
Tue Jun 27 05:54:43 2017 : Debug: (1) modsingle[post-auth]: calling
attr_filter.access_reject (rlm_attr_filter)
Tue Jun 27 05:54:43 2017 : Debug: %{User-Name}
Tue Jun 27 05:54:43 2017 : Debug: Parsed xlat tree:
Tue Jun 27 05:54:43 2017 : Debug: attribute --> User-Name
Tue Jun 27 05:54:43 2017 : Debug: (1) attr_filter.access_reject: EXPAND
%{User-Name}
Tue Jun 27 05:54:43 2017 : Debug: (1) attr_filter.access_reject: --> teke
Tue Jun 27 05:54:43 2017 : Debug: (1) attr_filter.access_reject: Matched
entry DEFAULT at line 11
Tue Jun 27 05:54:43 2017 : Debug: (1) modsingle[post-auth]: returned
from attr_filter.access_reject (rlm_attr_filter)
Tue Jun 27 05:54:43 2017 : Debug: (1) [attr_filter.access_reject] =
updated
Tue Jun 27 05:54:43 2017 : Debug: (1) modsingle[post-auth]: calling eap
(rlm_eap)
Tue Jun 27 05:54:43 2017 : Debug: (1) eap: Request didn't contain an
EAP-Message, not inserting EAP-Failure
Tue Jun 27 05:54:43 2017 : Debug: (1) modsingle[post-auth]: returned
from eap (rlm_eap)
Tue Jun 27 05:54:43 2017 : Debug: (1) [eap] = noop
Tue Jun 27 05:54:43 2017 : Debug: (1) policy
remove_reply_message_if_eap {
Tue Jun 27 05:54:43 2017 : Debug: (1) if (&reply:EAP-Message &&
&reply:Reply-Message) {
Tue Jun 27 05:54:43 2017 : Debug: (1) if (&reply:EAP-Message &&
&reply:Reply-Message) -> FALSE
Tue Jun 27 05:54:43 2017 : Debug: (1) else {
Tue Jun 27 05:54:43 2017 : Debug: (1) modsingle[post-auth]: calling
noop (rlm_always)
Tue Jun 27 05:54:43 2017 : Debug: (1) modsingle[post-auth]:
returned from noop (rlm_always)
Tue Jun 27 05:54:43 2017 : Debug: (1) [noop] = noop
Tue Jun 27 05:54:43 2017 : Debug: (1) } # else = noop
Tue Jun 27 05:54:43 2017 : Debug: (1) } # policy
remove_reply_message_if_eap = noop
Tue Jun 27 05:54:43 2017 : Debug: (1) } # Post-Auth-Type REJECT = updated
Tue Jun 27 05:54:43 2017 : Debug: (1) Delaying response for 1.000000 seconds
Tue Jun 27 05:54:43 2017 : Debug: Waking up in 0.9 seconds.
Tue Jun 27 05:54:44 2017 : Debug: (1) Sending delayed response
Tue Jun 27 05:54:44 2017 : Debug: (1) Sent Access-Reject Id 251 from
127.0.0.1:1812 to 127.0.0.1:53093 length 20
Tue Jun 27 05:54:44 2017 : Debug: Waking up in 3.9 seconds.
Tue Jun 27 05:54:48 2017 : Debug: (1) Cleaning up request packet ID 251
with timestamp +118720
Any kind of help, documentation recommendation would help. thankyou!
More information about the Freeradius-Users
mailing list