TLS cant connect ldap+freeradius+novell

Martin G kapten_kanelbulle at hotmail.com
Thu Jul 19 14:41:15 CEST 2007 

Hello!

Im new to both this mailinglist and to novell/linux/ldap/freeradius but iv 
tried my best to install a radius/ldap linuxserver to pass on 
radius-requests from a Aruba-controller to our novell-server.

IPs:
Novell 10.10.0.11
Aruba 10.10.0.28
Linux (freeradius+ldap) 10.10.0.132

Iv tried to change tls_mode, port and tls_start on and off a couple of times 
without any good result and when i go use ldapsearch -vvv -h 10.10.0.11 -x 
-Z -b ou=adm,ou=malmo,o=wifi "cn=lotta"
i recieve "TLS: hostname does not match CN in peer certificate".

So i have some thoughts about the certificate, but iv exported the 
selfsigned novell-certificate from the novellserver and verifyed it. But im 
not sure how to use a "client-certificate" on the linux.

When i use "freeradius -XXX -A" on the linuxserver and i trie to do a 
radius-request, the aruba gets a timeout and the linuxserver tells me the 
following logg:

Tue Jul 10 11:32:28 2007 : Info: Starting - reading configuration files ...
Tue Jul 10 11:32:28 2007 : Debug: reread_config:  reading radiusd.conf
Tue Jul 10 11:32:28 2007 : Debug: Config:   including file: 
/etc/freeradius/proxy.conf
Tue Jul 10 11:32:28 2007 : Debug: Config:   including file: 
/etc/freeradius/clients.conf
Tue Jul 10 11:32:28 2007 : Debug: Config:   including file: 
/etc/freeradius/snmp.conf
Tue Jul 10 11:32:28 2007 : Debug: Config:   including file: 
/etc/freeradius/eap.conf
Tue Jul 10 11:32:28 2007 : Debug: Config:   including file: 
/etc/freeradius/sql.conf
Tue Jul 10 11:32:28 2007 : Debug:  main: prefix = "/usr"
Tue Jul 10 11:32:28 2007 : Debug:  main: localstatedir = "/var"
Tue Jul 10 11:32:28 2007 : Debug:  main: logdir = "/var/log/freeradius"
Tue Jul 10 11:32:28 2007 : Debug:  main: libdir = "/usr/lib/freeradius"
Tue Jul 10 11:32:28 2007 : Debug:  main: radacctdir = 
"/var/log/freeradius/radacct"
Tue Jul 10 11:32:28 2007 : Debug:  main: hostname_lookups = no
Tue Jul 10 11:32:28 2007 : Debug:  main: max_request_time = 30
Tue Jul 10 11:32:28 2007 : Debug:  main: cleanup_delay = 5
Tue Jul 10 11:32:28 2007 : Debug:  main: max_requests = 1024
Tue Jul 10 11:32:28 2007 : Debug:  main: delete_blocked_requests = 0
Tue Jul 10 11:32:28 2007 : Debug:  main: port = 0
Tue Jul 10 11:32:28 2007 : Debug:  main: allow_core_dumps = no
Tue Jul 10 11:32:28 2007 : Debug:  main: log_stripped_names = yes
Tue Jul 10 11:32:28 2007 : Debug:  main: log_file = 
"/var/log/freeradius/radius.log"
Tue Jul 10 11:32:28 2007 : Debug:  main: log_auth = yes
Tue Jul 10 11:32:28 2007 : Debug:  main: log_auth_badpass = yes
Tue Jul 10 11:32:28 2007 : Debug:  main: log_auth_goodpass = yes
Tue Jul 10 11:32:28 2007 : Debug:  main: pidfile = 
"/var/run/freeradius/freeradius.pid"
Tue Jul 10 11:32:28 2007 : Debug:  main: user = "freerad"
Tue Jul 10 11:32:28 2007 : Debug:  main: group = "freerad"
Tue Jul 10 11:32:28 2007 : Debug:  main: usercollide = no
Tue Jul 10 11:32:28 2007 : Debug:  main: lower_user = "no"
Tue Jul 10 11:32:28 2007 : Debug:  main: lower_pass = "no"
Tue Jul 10 11:32:28 2007 : Debug:  main: nospace_user = "no"
Tue Jul 10 11:32:28 2007 : Debug:  main: nospace_pass = "no"
Tue Jul 10 11:32:28 2007 : Debug:  main: checkrad = "/usr/sbin/checkrad"
Tue Jul 10 11:32:28 2007 : Debug:  main: proxy_requests = yes
Tue Jul 10 11:32:28 2007 : Debug:  proxy: retry_delay = 5
Tue Jul 10 11:32:28 2007 : Debug:  proxy: retry_count = 3
Tue Jul 10 11:32:28 2007 : Debug:  proxy: synchronous = no
Tue Jul 10 11:32:28 2007 : Debug:  proxy: default_fallback = yes
Tue Jul 10 11:32:28 2007 : Debug:  proxy: dead_time = 120
Tue Jul 10 11:32:28 2007 : Debug:  proxy: post_proxy_authorize = no
Tue Jul 10 11:32:28 2007 : Debug:  proxy: wake_all_if_all_dead = no
Tue Jul 10 11:32:28 2007 : Debug:  security: max_attributes = 200
Tue Jul 10 11:32:28 2007 : Debug:  security: reject_delay = 1
Tue Jul 10 11:32:28 2007 : Debug:  security: status_server = no
Tue Jul 10 11:32:28 2007 : Debug:  main: debug_level = 0
Tue Jul 10 11:32:28 2007 : Debug: read_config_files:  reading dictionary
Tue Jul 10 11:32:28 2007 : Debug: read_config_files:  reading naslist
Tue Jul 10 11:32:28 2007 : Info: Using deprecated naslist file.  Support for 
this will go away soon.
Tue Jul 10 11:32:28 2007 : Debug: read_config_files:  reading clients
Tue Jul 10 11:32:28 2007 : Debug: read_config_files:  reading realms
Tue Jul 10 11:32:28 2007 : Debug: radiusd:  entering modules setup
Tue Jul 10 11:32:28 2007 : Debug: Module: Library search path is 
/usr/lib/freeradius
Tue Jul 10 11:32:28 2007 : Debug: Module: Loaded exec
Tue Jul 10 11:32:28 2007 : Debug:  exec: wait = yes
Tue Jul 10 11:32:28 2007 : Debug:  exec: program = "(null)"
Tue Jul 10 11:32:28 2007 : Debug:  exec: input_pairs = "request"
Tue Jul 10 11:32:28 2007 : Debug:  exec: output_pairs = "(null)"
Tue Jul 10 11:32:28 2007 : Debug:  exec: packet_type = "(null)"
Tue Jul 10 11:32:28 2007 : Info: rlm_exec: Wait=yes but no output defined. 
Did you mean output=none?
Tue Jul 10 11:32:28 2007 : Debug: Module: Instantiated exec (exec)
Tue Jul 10 11:32:28 2007 : Debug: Module: Loaded expr
Tue Jul 10 11:32:28 2007 : Debug: Module: Instantiated expr (expr)
Tue Jul 10 11:32:28 2007 : Debug: Module: Loaded PAP
Tue Jul 10 11:32:28 2007 : Debug:  pap: encryption_scheme = "crypt"
Tue Jul 10 11:32:28 2007 : Debug: Module: Instantiated pap (pap)
Tue Jul 10 11:32:28 2007 : Debug: Module: Loaded CHAP
Tue Jul 10 11:32:28 2007 : Debug: Module: Instantiated chap (chap)
Tue Jul 10 11:32:28 2007 : Debug: Module: Loaded MS-CHAP
Tue Jul 10 11:32:28 2007 : Debug:  mschap: use_mppe = yes
Tue Jul 10 11:32:28 2007 : Debug:  mschap: require_encryption = no
Tue Jul 10 11:32:28 2007 : Debug:  mschap: require_strong = no
Tue Jul 10 11:32:28 2007 : Debug:  mschap: with_ntdomain_hack = no
Tue Jul 10 11:32:28 2007 : Debug:  mschap: passwd = "(null)"
Tue Jul 10 11:32:28 2007 : Debug:  mschap: ntlm_auth = "(null)"
Tue Jul 10 11:32:28 2007 : Debug: Module: Instantiated mschap (mschap)
Tue Jul 10 11:32:28 2007 : Debug: Module: Loaded System
Tue Jul 10 11:32:28 2007 : Debug:  unix: cache = no
Tue Jul 10 11:32:28 2007 : Debug:  unix: passwd = "(null)"
Tue Jul 10 11:32:28 2007 : Debug:  unix: shadow = "/etc/shadow"
Tue Jul 10 11:32:28 2007 : Debug:  unix: group = "(null)"
Tue Jul 10 11:32:28 2007 : Debug:  unix: radwtmp = 
"/var/log/freeradius/radwtmp"
Tue Jul 10 11:32:28 2007 : Debug:  unix: usegroup = no
Tue Jul 10 11:32:28 2007 : Debug:  unix: cache_reload = 600
Tue Jul 10 11:32:28 2007 : Debug: Module: Instantiated unix (unix)
Tue Jul 10 11:32:28 2007 : Debug: Module: Loaded LDAP
Tue Jul 10 11:32:28 2007 : Debug:  ldap: server = "10.10.0.11"
Tue Jul 10 11:32:28 2007 : Debug:  ldap: port = 636
Tue Jul 10 11:32:28 2007 : Debug:  ldap: net_timeout = 1
Tue Jul 10 11:32:28 2007 : Debug:  ldap: timeout = 4
Tue Jul 10 11:32:28 2007 : Debug:  ldap: timelimit = 3
Tue Jul 10 11:32:28 2007 : Debug:  ldap: identity = "cn=admin,o=wifi"
Tue Jul 10 11:32:28 2007 : Debug:  ldap: tls_mode = no
Tue Jul 10 11:32:28 2007 : Debug:  ldap: start_tls = yes
Tue Jul 10 11:32:28 2007 : Debug:  ldap: tls_cacertfile = 
"/etc/freeradius/certs/WIFITREE_CA.b64"
Tue Jul 10 11:32:28 2007 : Debug:  ldap: tls_certfile = 
"/etc/freeradius/certs/WIFITREE_CA.b64"
Tue Jul 10 11:32:28 2007 : Debug:  ldap: tls_cacertdir = "(null)"
Tue Jul 10 11:32:28 2007 : Debug:  ldap: tls_keyfile = "(null)"
Tue Jul 10 11:32:28 2007 : Debug:  ldap: tls_randfile = "(null)"
Tue Jul 10 11:32:28 2007 : Debug:  ldap: tls_require_cert = "allow"
Tue Jul 10 11:32:28 2007 : Debug:  ldap: password = "******"
Tue Jul 10 11:32:28 2007 : Debug:  ldap: basedn = "ou=adm,ou=malmo,o=wifi"
Tue Jul 10 11:32:28 2007 : Debug:  ldap: filter = 
"(cn=%{Stripped-User-Name:-%{User-Name}})"
Tue Jul 10 11:32:28 2007 : Debug:  ldap: base_filter = 
"(objectclass=radiusprofile)"
Tue Jul 10 11:32:28 2007 : Debug:  ldap: default_profile = "(null)"
Tue Jul 10 11:32:28 2007 : Debug:  ldap: profile_attribute = "(null)"
Tue Jul 10 11:32:28 2007 : Debug:  ldap: password_header = "(null)"
Tue Jul 10 11:32:28 2007 : Debug:  ldap: password_attribute = "nspmPassword"
Tue Jul 10 11:32:28 2007 : Debug:  ldap: access_attr = "dialupAccess"
Tue Jul 10 11:32:28 2007 : Debug:  ldap: groupname_attribute = "cn"
Tue Jul 10 11:32:28 2007 : Debug:  ldap: groupmembership_filter = 
"(|(&(objectClass=GroupOfNames)(member=%{Ldap-UserDn}))(&(objectClass=GroupOfUniqueNames)(uniquemember=%{Ldap-UserDn})))"
Tue Jul 10 11:32:28 2007 : Debug:  ldap: groupmembership_attribute = 
"(null)"
Tue Jul 10 11:32:28 2007 : Debug:  ldap: dictionary_mapping = 
"/etc/freeradius/ldap.attrmap"
Tue Jul 10 11:32:28 2007 : Debug:  ldap: ldap_debug = 0
Tue Jul 10 11:32:28 2007 : Debug:  ldap: ldap_connections_number = 5
Tue Jul 10 11:32:28 2007 : Debug:  ldap: compare_check_items = no
Tue Jul 10 11:32:28 2007 : Debug:  ldap: access_attr_used_for_allow = yes
Tue Jul 10 11:32:28 2007 : Debug:  ldap: do_xlat = yes
Tue Jul 10 11:32:28 2007 : Debug:  ldap: edir_account_policy_check = yes
Tue Jul 10 11:32:28 2007 : Debug:  ldap: set_auth_type = yes
Tue Jul 10 11:32:28 2007 : Debug: rlm_ldap: Registering ldap_groupcmp for 
Ldap-Group
Tue Jul 10 11:32:28 2007 : Debug: rlm_ldap: Registering ldap_xlat with 
xlat_name ldap
Tue Jul 10 11:32:28 2007 : Debug: rlm_ldap: reading ldap<->radius mappings 
from file /etc/freeradius/ldap.attrmap
Tue Jul 10 11:32:28 2007 : Debug: rlm_ldap: LDAP radiusCheckItem mapped to 
RADIUS $GENERIC$
Tue Jul 10 11:32:28 2007 : Debug: rlm_ldap: LDAP radiusReplyItem mapped to 
RADIUS $GENERIC$
Tue Jul 10 11:32:28 2007 : Debug: rlm_ldap: LDAP radiusAuthType mapped to 
RADIUS Auth-Type
Tue Jul 10 11:32:28 2007 : Debug: rlm_ldap: LDAP radiusSimultaneousUse 
mapped to RADIUS Simultaneous-Use
Tue Jul 10 11:32:28 2007 : Debug: rlm_ldap: LDAP radiusCalledStationId 
mapped to RADIUS Called-Station-Id
Tue Jul 10 11:32:28 2007 : Debug: rlm_ldap: LDAP radiusCallingStationId 
mapped to RADIUS Calling-Station-Id
Tue Jul 10 11:32:28 2007 : Debug: rlm_ldap: LDAP lmPassword mapped to RADIUS 
LM-Password
Tue Jul 10 11:32:28 2007 : Debug: rlm_ldap: LDAP ntPassword mapped to RADIUS 
NT-Password
Tue Jul 10 11:32:28 2007 : Debug: rlm_ldap: LDAP acctFlags mapped to RADIUS 
SMB-Account-CTRL-TEXT
Tue Jul 10 11:32:28 2007 : Debug: rlm_ldap: LDAP radiusExpiration mapped to 
RADIUS Expiration
Tue Jul 10 11:32:28 2007 : Debug: rlm_ldap: LDAP radiusNASIpAddress mapped 
to RADIUS NAS-IP-Address
Tue Jul 10 11:32:28 2007 : Debug: rlm_ldap: LDAP radiusServiceType mapped to 
RADIUS Service-Type
Tue Jul 10 11:32:28 2007 : Debug: rlm_ldap: LDAP radiusFramedProtocol mapped 
to RADIUS Framed-Protocol
Tue Jul 10 11:32:28 2007 : Debug: rlm_ldap: LDAP radiusFramedIPAddress 
mapped to RADIUS Framed-IP-Address
Tue Jul 10 11:32:28 2007 : Debug: rlm_ldap: LDAP radiusFramedIPNetmask 
mapped to RADIUS Framed-IP-Netmask
Tue Jul 10 11:32:28 2007 : Debug: rlm_ldap: LDAP radiusFramedRoute mapped to 
RADIUS Framed-Route
Tue Jul 10 11:32:28 2007 : Debug: rlm_ldap: LDAP radiusFramedRouting mapped 
to RADIUS Framed-Routing
Tue Jul 10 11:32:28 2007 : Debug: rlm_ldap: LDAP radiusFilterId mapped to 
RADIUS Filter-Id
Tue Jul 10 11:32:28 2007 : Debug: rlm_ldap: LDAP radiusFramedMTU mapped to 
RADIUS Framed-MTU
Tue Jul 10 11:32:28 2007 : Debug: rlm_ldap: LDAP radiusFramedCompression 
mapped to RADIUS Framed-Compression
Tue Jul 10 11:32:28 2007 : Debug: rlm_ldap: LDAP radiusLoginIPHost mapped to 
RADIUS Login-IP-Host
Tue Jul 10 11:32:28 2007 : Debug: rlm_ldap: LDAP radiusLoginService mapped 
to RADIUS Login-Service
Tue Jul 10 11:32:28 2007 : Debug: rlm_ldap: LDAP radiusLoginTCPPort mapped 
to RADIUS Login-TCP-Port
Tue Jul 10 11:32:28 2007 : Debug: rlm_ldap: LDAP radiusCallbackNumber mapped 
to RADIUS Callback-Number
Tue Jul 10 11:32:28 2007 : Debug: rlm_ldap: LDAP radiusCallbackId mapped to 
RADIUS Callback-Id
Tue Jul 10 11:32:28 2007 : Debug: rlm_ldap: LDAP radiusFramedIPXNetwork 
mapped to RADIUS Framed-IPX-Network
Tue Jul 10 11:32:28 2007 : Debug: rlm_ldap: LDAP radiusClass mapped to 
RADIUS Class
Tue Jul 10 11:32:28 2007 : Debug: rlm_ldap: LDAP radiusSessionTimeout mapped 
to RADIUS Session-Timeout
Tue Jul 10 11:32:28 2007 : Debug: rlm_ldap: LDAP radiusIdleTimeout mapped to 
RADIUS Idle-Timeout
Tue Jul 10 11:32:28 2007 : Debug: rlm_ldap: LDAP radiusTerminationAction 
mapped to RADIUS Termination-Action
Tue Jul 10 11:32:28 2007 : Debug: rlm_ldap: LDAP radiusLoginLATService 
mapped to RADIUS Login-LAT-Service
Tue Jul 10 11:32:28 2007 : Debug: rlm_ldap: LDAP radiusLoginLATNode mapped 
to RADIUS Login-LAT-Node
Tue Jul 10 11:32:28 2007 : Debug: rlm_ldap: LDAP radiusLoginLATGroup mapped 
to RADIUS Login-LAT-Group
Tue Jul 10 11:32:28 2007 : Debug: rlm_ldap: LDAP radiusFramedAppleTalkLink 
mapped to RADIUS Framed-AppleTalk-Link
Tue Jul 10 11:32:28 2007 : Debug: rlm_ldap: LDAP 
radiusFramedAppleTalkNetwork mapped to RADIUS Framed-AppleTalk-Network
Tue Jul 10 11:32:28 2007 : Debug: rlm_ldap: LDAP radiusFramedAppleTalkZone 
mapped to RADIUS Framed-AppleTalk-Zone
Tue Jul 10 11:32:28 2007 : Debug: rlm_ldap: LDAP radiusPortLimit mapped to 
RADIUS Port-Limit
Tue Jul 10 11:32:28 2007 : Debug: rlm_ldap: LDAP radiusLoginLATPort mapped 
to RADIUS Login-LAT-Port
Tue Jul 10 11:32:28 2007 : Debug: rlm_ldap: LDAP radiusReplyMessage mapped 
to RADIUS Reply-Message
Tue Jul 10 11:32:28 2007 : Debug: conns: 0x8145988
Tue Jul 10 11:32:28 2007 : Debug: Module: Instantiated ldap (ldap)
Tue Jul 10 11:32:28 2007 : Debug: Module: Loaded eap
Tue Jul 10 11:32:28 2007 : Debug:  eap: default_eap_type = "md5"
Tue Jul 10 11:32:28 2007 : Debug:  eap: timer_expire = 60
Tue Jul 10 11:32:28 2007 : Debug:  eap: ignore_unknown_eap_types = no
Tue Jul 10 11:32:28 2007 : Debug:  eap: cisco_accounting_username_bug = no
Tue Jul 10 11:32:28 2007 : Debug: rlm_eap: Loaded and initialized type md5
Tue Jul 10 11:32:28 2007 : Debug: rlm_eap: Loaded and initialized type leap
Tue Jul 10 11:32:28 2007 : Debug:  gtc: challenge = "Password: "
Tue Jul 10 11:32:28 2007 : Debug:  gtc: auth_type = "PAP"
Tue Jul 10 11:32:28 2007 : Debug: rlm_eap: Loaded and initialized type gtc
Tue Jul 10 11:32:28 2007 : Debug:  mschapv2: with_ntdomain_hack = no
Tue Jul 10 11:32:28 2007 : Debug: rlm_eap: Loaded and initialized type 
mschapv2
Tue Jul 10 11:32:28 2007 : Debug: Module: Instantiated eap (eap)
Tue Jul 10 11:32:28 2007 : Debug: Module: Loaded preprocess
Tue Jul 10 11:32:28 2007 : Debug:  preprocess: huntgroups = 
"/etc/freeradius/huntgroups"
Tue Jul 10 11:32:28 2007 : Debug:  preprocess: hints = 
"/etc/freeradius/hints"
Tue Jul 10 11:32:28 2007 : Debug:  preprocess: with_ascend_hack = no
Tue Jul 10 11:32:28 2007 : Debug:  preprocess: ascend_channels_per_line = 23
Tue Jul 10 11:32:28 2007 : Debug:  preprocess: with_ntdomain_hack = no
Tue Jul 10 11:32:28 2007 : Debug:  preprocess: with_specialix_jetstream_hack 
= no
Tue Jul 10 11:32:28 2007 : Debug:  preprocess: with_cisco_vsa_hack = no
Tue Jul 10 11:32:28 2007 : Debug:  preprocess: with_alvarion_vsa_hack = no
Tue Jul 10 11:32:28 2007 : Debug: Module: Instantiated preprocess 
(preprocess)
Tue Jul 10 11:32:28 2007 : Debug: Module: Loaded realm
Tue Jul 10 11:32:28 2007 : Debug:  realm: format = "suffix"
Tue Jul 10 11:32:28 2007 : Debug:  realm: delimiter = "@"
Tue Jul 10 11:32:28 2007 : Debug:  realm: ignore_default = no
Tue Jul 10 11:32:28 2007 : Debug:  realm: ignore_null = no
Tue Jul 10 11:32:28 2007 : Debug: Module: Instantiated realm (suffix)
Tue Jul 10 11:32:28 2007 : Debug: Module: Loaded files
Tue Jul 10 11:32:28 2007 : Debug:  files: usersfile = 
"/etc/freeradius/users"
Tue Jul 10 11:32:28 2007 : Debug:  files: acctusersfile = 
"/etc/freeradius/acct_users"
Tue Jul 10 11:32:28 2007 : Debug:  files: preproxy_usersfile = 
"/etc/freeradius/preproxy_users"
Tue Jul 10 11:32:28 2007 : Debug:  files: compat = "no"
Tue Jul 10 11:32:28 2007 : Debug: Module: Instantiated files (files)
Tue Jul 10 11:32:28 2007 : Debug: Module: Loaded Acct-Unique-Session-Id
Tue Jul 10 11:32:28 2007 : Debug:  acct_unique: key = "User-Name, 
Acct-Session-Id, NAS-IP-Address, Client-IP-Address, NAS-Port"
Tue Jul 10 11:32:28 2007 : Debug: Module: Instantiated acct_unique 
(acct_unique)
Tue Jul 10 11:32:28 2007 : Debug: Module: Loaded detail
Tue Jul 10 11:32:28 2007 : Debug:  detail: detailfile = 
"/var/log/freeradius/radacct/%{Client-IP-Address}/detail-%Y%m%d"
Tue Jul 10 11:32:28 2007 : Debug:  detail: detailperm = 384
Tue Jul 10 11:32:28 2007 : Debug:  detail: dirperm = 493
Tue Jul 10 11:32:28 2007 : Debug:  detail: locking = no
Tue Jul 10 11:32:28 2007 : Debug: Module: Instantiated detail (detail)
Tue Jul 10 11:32:28 2007 : Debug: Module: Loaded radutmp
Tue Jul 10 11:32:28 2007 : Debug:  radutmp: filename = 
"/var/log/freeradius/radutmp"
Tue Jul 10 11:32:28 2007 : Debug:  radutmp: username = "%{User-Name}"
Tue Jul 10 11:32:28 2007 : Debug:  radutmp: case_sensitive = yes
Tue Jul 10 11:32:28 2007 : Debug:  radutmp: check_with_nas = yes
Tue Jul 10 11:32:28 2007 : Debug:  radutmp: perm = 384
Tue Jul 10 11:32:28 2007 : Debug:  radutmp: callerid = yes
Tue Jul 10 11:32:28 2007 : Debug: Module: Instantiated radutmp (radutmp)
Tue Jul 10 11:32:28 2007 : Debug: Listening on authentication *:1812
Tue Jul 10 11:32:28 2007 : Debug: Listening on accounting *:1813
Tue Jul 10 11:32:28 2007 : Info: Ready to process requests.
rad_recv: Access-Request packet from host 10.10.0.28:32795, id=42, 
length=112
	NAS-IP-Address = 10.10.0.29
	NAS-Port = 0
	NAS-Port-Type = Wireless-802.11
	User-Name = "lotta"
	User-Password = "********"
	Calling-Station-Id = "000000000000"
	Called-Station-Id = "000B86600DB2"
	Aruba-Essid-Name = ""
	Aruba-Location-Id = "0.0.0"
Tue Jul 10 11:32:29 2007 : Debug:   Processing the authorize section of 
radiusd.conf
Tue Jul 10 11:32:29 2007 : Debug: modcall: entering group authorize for 
request 0
Tue Jul 10 11:32:29 2007 : Debug:   modsingle[authorize]: calling preprocess 
(rlm_preprocess) for request 0
Tue Jul 10 11:32:29 2007 : Debug:   modsingle[authorize]: returned from 
preprocess (rlm_preprocess) for request 0
Tue Jul 10 11:32:29 2007 : Debug:   modcall[authorize]: module "preprocess" 
returns ok for request 0
Tue Jul 10 11:32:29 2007 : Debug:   modsingle[authorize]: calling chap 
(rlm_chap) for request 0
Tue Jul 10 11:32:29 2007 : Debug:   modsingle[authorize]: returned from chap 
(rlm_chap) for request 0
Tue Jul 10 11:32:29 2007 : Debug:   modcall[authorize]: module "chap" 
returns noop for request 0
Tue Jul 10 11:32:29 2007 : Debug:   modsingle[authorize]: calling mschap 
(rlm_mschap) for request 0
Tue Jul 10 11:32:29 2007 : Debug:   modsingle[authorize]: returned from 
mschap (rlm_mschap) for request 0
Tue Jul 10 11:32:29 2007 : Debug:   modcall[authorize]: module "mschap" 
returns noop for request 0
Tue Jul 10 11:32:29 2007 : Debug:   modsingle[authorize]: calling suffix 
(rlm_realm) for request 0
Tue Jul 10 11:32:29 2007 : Debug:     rlm_realm: No '@' in User-Name = 
"lotta", looking up realm NULL
Tue Jul 10 11:32:29 2007 : Debug:     rlm_realm: No such realm "NULL"
Tue Jul 10 11:32:29 2007 : Debug:   modsingle[authorize]: returned from 
suffix (rlm_realm) for request 0
Tue Jul 10 11:32:29 2007 : Debug:   modcall[authorize]: module "suffix" 
returns noop for request 0
Tue Jul 10 11:32:29 2007 : Debug:   modsingle[authorize]: calling eap 
(rlm_eap) for request 0
Tue Jul 10 11:32:29 2007 : Debug:   rlm_eap: No EAP-Message, not doing EAP
Tue Jul 10 11:32:29 2007 : Debug:   modsingle[authorize]: returned from eap 
(rlm_eap) for request 0
Tue Jul 10 11:32:29 2007 : Debug:   modcall[authorize]: module "eap" returns 
noop for request 0
Tue Jul 10 11:32:29 2007 : Debug:   modsingle[authorize]: calling files 
(rlm_files) for request 0
Tue Jul 10 11:32:29 2007 : Debug:     users: Matched entry DEFAULT at line 
152
Tue Jul 10 11:32:29 2007 : Debug:   modsingle[authorize]: returned from 
files (rlm_files) for request 0
Tue Jul 10 11:32:29 2007 : Debug:   modcall[authorize]: module "files" 
returns ok for request 0
Tue Jul 10 11:32:29 2007 : Debug:   modsingle[authorize]: calling ldap 
(rlm_ldap) for request 0
Tue Jul 10 11:32:29 2007 : Debug: rlm_ldap: - authorize
Tue Jul 10 11:32:29 2007 : Debug: rlm_ldap: performing user authorization 
for lotta
Tue Jul 10 11:32:29 2007 : Debug: radius_xlat:  '(cn=lotta)'
Tue Jul 10 11:32:29 2007 : Debug: radius_xlat:  'ou=adm,ou=malmo,o=wifi'
Tue Jul 10 11:32:29 2007 : Debug: rlm_ldap: ldap_get_conn: Checking Id: 0
Tue Jul 10 11:32:29 2007 : Debug: rlm_ldap: ldap_get_conn: Got Id: 0
Tue Jul 10 11:32:29 2007 : Debug: rlm_ldap: attempting LDAP reconnection
Tue Jul 10 11:32:29 2007 : Debug: rlm_ldap: (re)connect to 10.10.0.11:636, 
authentication 0
Tue Jul 10 11:32:29 2007 : Debug: rlm_ldap: setting TLS mode to 1
Tue Jul 10 11:32:29 2007 : Debug: rlm_ldap: setting TLS CACert File to 
/etc/freeradius/certs/WIFITREE_CA.b64
Tue Jul 10 11:32:29 2007 : Debug: rlm_ldap: setting TLS CACert Directory to 
/etc/freeradius/certs/
Tue Jul 10 11:32:29 2007 : Debug: rlm_ldap: setting TLS Cert File to 
/etc/freeradius/certs/WIFITREE_CA.b64
Tue Jul 10 11:32:29 2007 : Debug: rlm_ldap: starting TLS
Tue Jul 10 11:32:30 2007 : Debug: rlm_ldap: ldap_start_tls_s()
Tue Jul 10 11:32:30 2007 : Error: rlm_ldap: could not start TLS Can't 
contact LDAP server
Tue Jul 10 11:32:30 2007 : Error: rlm_ldap: (re)connection attempt failed
Tue Jul 10 11:32:30 2007 : Debug: rlm_ldap: search failed
Tue Jul 10 11:32:30 2007 : Debug: rlm_ldap: ldap_release_conn: Release Id: 0
Tue Jul 10 11:32:30 2007 : Debug:   modsingle[authorize]: returned from ldap 
(rlm_ldap) for request 0
Tue Jul 10 11:32:30 2007 : Debug:   modcall[authorize]: module "ldap" 
returns fail for request 0
Tue Jul 10 11:32:30 2007 : Debug: modcall: leaving group authorize (returns 
fail) for request 0
Tue Jul 10 11:32:30 2007 : Debug: Finished request 0
Tue Jul 10 11:32:30 2007 : Debug: Going to the next request
Tue Jul 10 11:32:30 2007 : Debug: --- Walking the entire request list ---
Tue Jul 10 11:32:30 2007 : Debug: Waking up in 6 seconds...
rad_recv: Access-Request packet from host 10.10.0.28:32795, id=42, 
length=112
Tue Jul 10 11:32:31 2007 : Debug: Discarding duplicate request from client 
localhost:32795 - ID: 42
Tue Jul 10 11:32:31 2007 : Debug: --- Walking the entire request list ---
Tue Jul 10 11:32:31 2007 : Debug: Waking up in 4 seconds...
rad_recv: Access-Request packet from host 10.10.0.28:32795, id=42, 
length=112
Tue Jul 10 11:32:33 2007 : Debug: Discarding duplicate request from client 
localhost:32795 - ID: 42
Tue Jul 10 11:32:33 2007 : Debug: --- Walking the entire request list ---
Tue Jul 10 11:32:33 2007 : Debug: Waking up in 2 seconds...
Tue Jul 10 11:32:35 2007 : Debug: --- Walking the entire request list ---
Tue Jul 10 11:32:35 2007 : Debug: Cleaning up request 0 ID 42 with timestamp 
4693522d
Tue Jul 10 11:32:35 2007 : Debug: Nothing to do.  Sleeping until we see a 
request.
rad_recv: Access-Request packet from host 10.10.0.28:32795, id=42, 
length=112
	NAS-IP-Address = 10.10.0.29
	NAS-Port = 0
	NAS-Port-Type = Wireless-802.11
	User-Name = "lotta"
	User-Password = "******"
	Calling-Station-Id = "000000000000"
	Called-Station-Id = "000B86600DB2"
	Aruba-Essid-Name = ""
	Aruba-Location-Id = "0.0.0"
Tue Jul 10 11:32:35 2007 : Debug:   Processing the authorize section of 
radiusd.conf
Tue Jul 10 11:32:35 2007 : Debug: modcall: entering group authorize for 
request 1
Tue Jul 10 11:32:35 2007 : Debug:   modsingle[authorize]: calling preprocess 
(rlm_preprocess) for request 1
Tue Jul 10 11:32:35 2007 : Debug:   modsingle[authorize]: returned from 
preprocess (rlm_preprocess) for request 1
Tue Jul 10 11:32:35 2007 : Debug:   modcall[authorize]: module "preprocess" 
returns ok for request 1
Tue Jul 10 11:32:35 2007 : Debug:   modsingle[authorize]: calling chap 
(rlm_chap) for request 1
Tue Jul 10 11:32:35 2007 : Debug:   modsingle[authorize]: returned from chap 
(rlm_chap) for request 1
Tue Jul 10 11:32:35 2007 : Debug:   modcall[authorize]: module "chap" 
returns noop for request 1
Tue Jul 10 11:32:35 2007 : Debug:   modsingle[authorize]: calling mschap 
(rlm_mschap) for request 1
Tue Jul 10 11:32:35 2007 : Debug:   modsingle[authorize]: returned from 
mschap (rlm_mschap) for request 1
Tue Jul 10 11:32:35 2007 : Debug:   modcall[authorize]: module "mschap" 
returns noop for request 1
Tue Jul 10 11:32:35 2007 : Debug:   modsingle[authorize]: calling suffix 
(rlm_realm) for request 1
Tue Jul 10 11:32:35 2007 : Debug:     rlm_realm: No '@' in User-Name = 
"lotta", looking up realm NULL
Tue Jul 10 11:32:35 2007 : Debug:     rlm_realm: No such realm "NULL"
Tue Jul 10 11:32:35 2007 : Debug:   modsingle[authorize]: returned from 
suffix (rlm_realm) for request 1
Tue Jul 10 11:32:35 2007 : Debug:   modcall[authorize]: module "suffix" 
returns noop for request 1
Tue Jul 10 11:32:35 2007 : Debug:   modsingle[authorize]: calling eap 
(rlm_eap) for request 1
Tue Jul 10 11:32:35 2007 : Debug:   rlm_eap: No EAP-Message, not doing EAP
Tue Jul 10 11:32:35 2007 : Debug:   modsingle[authorize]: returned from eap 
(rlm_eap) for request 1
Tue Jul 10 11:32:35 2007 : Debug:   modcall[authorize]: module "eap" returns 
noop for request 1
Tue Jul 10 11:32:35 2007 : Debug:   modsingle[authorize]: calling files 
(rlm_files) for request 1
Tue Jul 10 11:32:35 2007 : Debug:     users: Matched entry DEFAULT at line 
152
Tue Jul 10 11:32:35 2007 : Debug:   modsingle[authorize]: returned from 
files (rlm_files) for request 1
Tue Jul 10 11:32:35 2007 : Debug:   modcall[authorize]: module "files" 
returns ok for request 1
Tue Jul 10 11:32:35 2007 : Debug:   modsingle[authorize]: calling ldap 
(rlm_ldap) for request 1
Tue Jul 10 11:32:35 2007 : Debug: rlm_ldap: - authorize
Tue Jul 10 11:32:35 2007 : Debug: rlm_ldap: performing user authorization 
for lotta
Tue Jul 10 11:32:35 2007 : Debug: radius_xlat:  '(cn=lotta)'
Tue Jul 10 11:32:35 2007 : Debug: radius_xlat:  'ou=adm,ou=malmo,o=wifi'
Tue Jul 10 11:32:35 2007 : Debug: rlm_ldap: ldap_get_conn: Checking Id: 0
Tue Jul 10 11:32:35 2007 : Debug: rlm_ldap: ldap_get_conn: Got Id: 0
Tue Jul 10 11:32:35 2007 : Debug: rlm_ldap: attempting LDAP reconnection
Tue Jul 10 11:32:35 2007 : Debug: rlm_ldap: (re)connect to 10.10.0.11:636, 
authentication 0
Tue Jul 10 11:32:35 2007 : Debug: rlm_ldap: setting TLS mode to 1
Tue Jul 10 11:32:35 2007 : Debug: rlm_ldap: setting TLS CACert File to 
/etc/freeradius/certs/WIFITREE_CA.b64
Tue Jul 10 11:32:35 2007 : Debug: rlm_ldap: setting TLS CACert Directory to 
/etc/freeradius/certs/
Tue Jul 10 11:32:35 2007 : Debug: rlm_ldap: setting TLS Cert File to 
/etc/freeradius/certs/WIFITREE_CA.b64
Tue Jul 10 11:32:35 2007 : Debug: rlm_ldap: starting TLS
Tue Jul 10 11:32:35 2007 : Debug: rlm_ldap: ldap_start_tls_s()
Tue Jul 10 11:32:35 2007 : Error: rlm_ldap: could not start TLS Can't 
contact LDAP server
Tue Jul 10 11:32:35 2007 : Error: rlm_ldap: (re)connection attempt failed
Tue Jul 10 11:32:35 2007 : Debug: rlm_ldap: search failed
Tue Jul 10 11:32:35 2007 : Debug: rlm_ldap: ldap_release_conn: Release Id: 0
Tue Jul 10 11:32:35 2007 : Debug:   modsingle[authorize]: returned from ldap 
(rlm_ldap) for request 1
Tue Jul 10 11:32:35 2007 : Debug:   modcall[authorize]: module "ldap" 
returns fail for request 1
Tue Jul 10 11:32:35 2007 : Debug: modcall: leaving group authorize (returns 
fail) for request 1
Tue Jul 10 11:32:35 2007 : Debug: Finished request 1
Tue Jul 10 11:32:35 2007 : Debug: Going to the next request
Tue Jul 10 11:32:35 2007 : Debug: --- Walking the entire request list ---
Tue Jul 10 11:32:35 2007 : Debug: Waking up in 6 seconds...

Hope someone got any help.
/Mr G

_________________________________________________________________
Express yourself instantly with MSN Messenger! Download today it's FREE! 
http://messenger.msn.click-url.com/go/onm00200471ave/direct/01/

More information about the Freeradius-Users mailing list