Freeradius -username for authentication is not picking from users file.

5 Aug 2013

      Hello,

I am trying to run the radtest on local machine which is CentOS 6.0. But am
getting the following error while sending the Access Request message from
client which is another machine.

The user name is defined in users file under /usr/local/etc/raddb. But
still am getting the error. I had provided the snapshot received on radiusd
–Xx in the end.  Can you please help me in figuring out the issue?

rad_recv: Access-Request packet from host 10.100.111.2 port 4061, id=60,
length=77

      User-Name = "rajeev"

      User-Password = "\334a\004\305\355x\321\332G\306\362b\226~\355+"

      NAS-IP-Address = 135.250.14.111

      NAS-Identifier = "login"

      NAS-Port = 3036

      NAS-Port-Type = Virtual

      Service-Type = Authenticate-Only

Fri Aug  2 16:45:38 2013 : Info: # Executing section authorize from file
/usr/local/etc/raddb/sites-enabled/default

Fri Aug  2 16:45:38 2013 : Info: +- entering group authorize {...}

Fri Aug  2 16:45:38 2013 : Info: ++[preprocess] returns ok

Fri Aug  2 16:45:38 2013 : Info: [suffix] No '@' in User-Name = "rajeev",
looking up realm NULL

Fri Aug  2 16:45:38 2013 : Info: [suffix] No such realm "NULL"

Radius -X Snapshot:

=~=~=~=~=~=~=~=~=~=~=~= PuTTY log 2013.08.02 16:40:08
=~=~=~=~=~=~=~=~=~=~=~=

pwdradiusd -Xx

Fri Aug  2 16:45:25 2013 : Info: FreeRADIUS Version 2.2.0, for host
x86_64-unknown-linux-gnu, built on Aug  1 2013 at 17:38:57

Fri Aug  2 16:45:25 2013 : Info: Copyright (C) 1999-2012 The FreeRADIUS
server project and contributors.

Fri Aug  2 16:45:25 2013 : Info: There is NO warranty; not even for
MERCHANTABILITY or FITNESS FOR A

Fri Aug  2 16:45:25 2013 : Info: PARTICULAR PURPOSE.

Fri Aug  2 16:45:25 2013 : Info: You may redistribute copies of FreeRADIUS
under the terms of the

Fri Aug  2 16:45:25 2013 : Info: GNU General Public License v2.

Fri Aug  2 16:45:25 2013 : Info: Starting - reading configuration files ...

Fri Aug  2 16:45:25 2013 : Debug: including configuration file
/usr/local/etc/raddb/radiusd.conf

Fri Aug  2 16:45:25 2013 : Debug: including configuration file
/usr/local/etc/raddb/clients.conf

Fri Aug  2 16:45:25 2013 : Debug: including files in directory
/usr/local/etc/raddb/modules/

Fri Aug  2 16:45:25 2013 : Debug: including configuration file
/usr/local/etc/raddb/modules/mac2vlan

Fri Aug  2 16:45:25 2013 : Debug: including configuration file
/usr/local/etc/raddb/modules/radrelay

Fri Aug  2 16:45:25 2013 : Debug: including configuration file
/usr/local/etc/raddb/modules/radutmp

Fri Aug  2 16:45:25 2013 : Debug: including configuration file
/usr/local/etc/raddb/modules/files

Fri Aug  2 16:45:25 2013 : Debug: including configuration file
/usr/local/etc/raddb/modules/passwd

Fri Aug  2 16:45:25 2013 : Debug: including configuration file
/usr/local/etc/raddb/modules/attr_filter

Fri Aug  2 16:45:25 2013 : Debug: including configuration file
/usr/local/etc/raddb/modules/digest

Fri Aug  2 16:45:25 2013 : Debug: including configuration file
/usr/local/etc/raddb/modules/sql_log

Fri Aug  2 16:45:25 2013 : Debug: including configuration file
/usr/local/etc/raddb/modules/policy

Fri Aug  2 16:45:25 2013 : Debug: including configuration file
/usr/local/etc/raddb/modules/chap

Fri Aug  2 16:45:25 2013 : Debug: including configuration file
/usr/local/etc/raddb/modules/counter

Fri Aug  2 16:45:25 2013 : Debug: including configuration file
/usr/local/etc/raddb/modules/preprocess

Fri Aug  2 16:45:25 2013 : Debug: including configuration file
/usr/local/etc/raddb/modules/inner-eap

Fri Aug  2 16:45:25 2013 : Debug: including configuration file
/usr/local/etc/raddb/modules/opendirectory

Fri Aug  2 16:45:25 2013 : Debug: including configuration file
/usr/local/etc/raddb/modules/mac2ip

Fri Aug  2 16:45:25 2013 : Debug: including configuration file
/usr/local/etc/raddb/modules/wimax

Fri Aug  2 16:45:25 2013 : Debug: including configuration file
/usr/local/etc/raddb/modules/unix

Fri Aug  2 16:45:25 2013 : Debug: including configuration file
/usr/local/etc/raddb/modules/rediswho

Fri Aug  2 16:45:25 2013 : Debug: including configuration file
/usr/local/etc/raddb/modules/krb5

Fri Aug  2 16:45:25 2013 : Debug: including configuration file
/usr/local/etc/raddb/modules/checkval

Fri Aug  2 16:45:25 2013 : Debug: including configuration file
/usr/local/etc/raddb/modules/ldap

Fri Aug  2 16:45:25 2013 : Debug: including configuration file
/usr/local/etc/raddb/modules/attr_rewrite

Fri Aug  2 16:45:25 2013 : Debug: including configuration file
/usr/local/etc/raddb/modules/sqlcounter_expire_on_login

Fri Aug  2 16:45:25 2013 : Debug: including configuration file
/usr/local/etc/raddb/modules/pam

Fri Aug  2 16:45:25 2013 : Debug: including configuration file
/usr/local/etc/raddb/modules/detail.log

Fri Aug  2 16:45:25 2013 : Debug: including configuration file
/usr/local/etc/raddb/modules/linelog

Fri Aug  2 16:45:25 2013 : Debug: including configuration file
/usr/local/etc/raddb/modules/realm

Fri Aug  2 16:45:25 2013 : Debug: including configuration file
/usr/local/etc/raddb/modules/expr

Fri Aug  2 16:45:25 2013 : Debug: including configuration file
/usr/local/etc/raddb/modules/dhcp_sqlippool

Fri Aug  2 16:45:25 2013 : Debug: including configuration file
/usr/local/etc/raddb/sql/mysql/ippool-dhcp.conf

Fri Aug  2 16:45:25 2013 : Debug: including configuration file
/usr/local/etc/raddb/modules/ntlm_auth

Fri Aug  2 16:45:25 2013 : Debug: including configuration file
/usr/local/etc/raddb/modules/cui

Fri Aug  2 16:45:25 2013 : Debug: including configuration file
/usr/local/etc/raddb/modules/exec

Fri Aug  2 16:45:25 2013 : Debug: including configuration file
/usr/local/etc/raddb/modules/etc_group

Fri Aug  2 16:45:25 2013 : Debug: including configuration file
/usr/local/etc/raddb/modules/detail.example.com

Fri Aug  2 16:45:25 2013 : Debug: including configuration file
/usr/local/etc/raddb/modules/smbpasswd

Fri Aug  2 16:45:25 2013 : Debug: including configuration file
/usr/local/etc/raddb/modules/dynamic_clients

Fri Aug  2 16:45:25 2013 : Debug: including configuration file
/usr/local/etc/raddb/modules/smsotp

Fri Aug  2 16:45:25 2013 : Debug: including configuration file
/usr/local/etc/raddb/modules/logintime

Fri Aug  2 16:45:25 2013 : Debug: including configuration file
/usr/local/etc/raddb/modules/replicate

Fri Aug  2 16:45:25 2013 : Debug: including configuration file
/usr/local/etc/raddb/modules/acct_unique

Fri Aug  2 16:45:25 2013 : Debug: including configuration file
/usr/local/etc/raddb/modules/detail

Fri Aug  2 16:45:25 2013 : Debug: including configuration file
/usr/local/etc/raddb/modules/pap

Fri Aug  2 16:45:25 2013 : Debug: including configuration file
/usr/local/etc/raddb/modules/ippool

Fri Aug  2 16:45:25 2013 : Debug: including configuration file
/usr/local/etc/raddb/modules/expiration

Fri Aug  2 16:45:25 2013 : Debug: including configuration file
/usr/local/etc/raddb/modules/redis

Fri Aug  2 16:45:25 2013 : Debug: including configuration file
/usr/local/etc/raddb/modules/echo

Fri Aug  2 16:45:25 2013 : Debug: including configuration file
/usr/local/etc/raddb/modules/otp

Fri Aug  2 16:45:25 2013 : Debug: including configuration file
/usr/local/etc/raddb/modules/cache

Fri Aug  2 16:45:25 2013 : Debug: including configuration file
/usr/local/etc/raddb/modules/perl

Fri Aug  2 16:45:25 2013 : Debug: including configuration file
/usr/local/etc/raddb/modules/mschap

Fri Aug  2 16:45:25 2013 : Debug: including configuration file
/usr/local/etc/raddb/modules/sradutmp

Fri Aug  2 16:45:25 2013 : Debug: including configuration file
/usr/local/etc/raddb/modules/soh

Fri Aug  2 16:45:25 2013 : Debug: including configuration file
/usr/local/etc/raddb/modules/always

Fri Aug  2 16:45:25 2013 : Debug: including configuration file
/usr/local/etc/raddb/eap.conf

Fri Aug  2 16:45:25 2013 : Debug: including configuration file
/usr/local/etc/raddb/policy.conf

Fri Aug  2 16:45:25 2013 : Debug: including files in directory
/usr/local/etc/raddb/sites-enabled/

Fri Aug  2 16:45:25 2013 : Debug: including configuration file
/usr/local/etc/raddb/sites-enabled/inner-tunnel

Fri Aug  2 16:45:25 2013 : Debug: including configuration file
/usr/local/etc/raddb/sites-enabled/default

Fri Aug  2 16:45:25 2013 : Debug: including configuration file
/usr/local/etc/raddb/sites-enabled/control-socket

Fri Aug  2 16:45:25 2013 : Debug: main {

Fri Aug  2 16:45:25 2013 : Debug: allow_core_dumps = no

Fri Aug  2 16:45:25 2013 : Debug: }

Fri Aug  2 16:45:25 2013 : Debug: including dictionary file
/usr/local/etc/raddb/dictionary

Fri Aug  2 16:45:25 2013 : Debug: main {

Fri Aug  2 16:45:25 2013 : Debug: name = "radiusd"

Fri Aug  2 16:45:25 2013 : Debug: prefix = "/usr/local"

Fri Aug  2 16:45:25 2013 : Debug: localstatedir = "/usr/local/var"

Fri Aug  2 16:45:25 2013 : Debug: sbindir = "/usr/local/sbin"

Fri Aug  2 16:45:25 2013 : Debug: logdir = "/usr/local/var/log/radius"

Fri Aug  2 16:45:25 2013 : Debug: run_dir = "/usr/local/var/run/radiusd"

Fri Aug  2 16:45:25 2013 : Debug: libdir = "/usr/local/lib"

Fri Aug  2 16:45:25 2013 : Debug: radacctdir =
"/usr/local/var/log/radius/radacct"

Fri Aug  2 16:45:25 2013 : Debug: hostname_lookups = no

Fri Aug  2 16:45:25 2013 : Debug: max_request_time = 30

Fri Aug  2 16:45:25 2013 : Debug: cleanup_delay = 5

Fri Aug  2 16:45:25 2013 : Debug: max_requests = 1024

Fri Aug  2 16:45:25 2013 : Debug: pidfile =
"/usr/local/var/run/radiusd/radiusd.pid"

Fri Aug  2 16:45:25 2013 : Debug: checkrad = "/usr/local/sbin/checkrad"

Fri Aug  2 16:45:25 2013 : Debug: debug_level = 0

Fri Aug  2 16:45:25 2013 : Debug: proxy_requests = no

Fri Aug  2 16:45:25 2013 : Debug:  log {

Fri Aug  2 16:45:25 2013 : Debug: stripped_names = no

Fri Aug  2 16:45:25 2013 : Debug: auth = no

Fri Aug  2 16:45:25 2013 : Debug: auth_badpass = no

Fri Aug  2 16:45:25 2013 : Debug: auth_goodpass = no

Fri Aug  2 16:45:25 2013 : Debug:  }

Fri Aug  2 16:45:25 2013 : Debug:  security {

Fri Aug  2 16:45:25 2013 : Debug: max_attributes = 200

Fri Aug  2 16:45:25 2013 : Debug: reject_delay = 1

Fri Aug  2 16:45:25 2013 : Debug: status_server = yes

Fri Aug  2 16:45:25 2013 : Debug:  }

Fri Aug  2 16:45:25 2013 : Debug: }

Fri Aug  2 16:45:25 2013 : Debug: radiusd: #### Loading Realms and Home
Servers ####

Fri Aug  2 16:45:25 2013 : Debug: radiusd: #### Loading Clients ####

Fri Aug  2 16:45:25 2013 : Debug:  client 10.100.111.0/24 {

Fri Aug  2 16:45:25 2013 : Debug: require_message_authenticator = no

Fri Aug  2 16:45:25 2013 : Debug: secret = "ABC123"

Fri Aug  2 16:45:25 2013 : Debug: shortname = "BTS111"

Fri Aug  2 16:45:25 2013 : Debug:  }

Fri Aug  2 16:45:25 2013 : Debug:  client 10.100.111.2/24 {

Fri Aug  2 16:45:25 2013 : Debug: ipaddr = 10.100.111.2

Fri Aug  2 16:45:25 2013 : Debug: require_message_authenticator = no

Fri Aug  2 16:45:25 2013 : Debug: secret = "ABC123"

Fri Aug  2 16:45:25 2013 : Debug: shortname = "BTS111"

Fri Aug  2 16:45:25 2013 : Debug: nastype = "other"

Fri Aug  2 16:45:25 2013 : Debug:  }

Fri Aug  2 16:45:25 2013 : Debug: radiusd: #### Instantiating modules ####

Fri Aug  2 16:45:25 2013 : Debug:  instantiate {

Fri Aug  2 16:45:25 2013 : Debug:     (Loaded rlm_exec, checking if it's
valid)

Fri Aug  2 16:45:25 2013 : Debug:  Module: Linked to module rlm_exec

Fri Aug  2 16:45:25 2013 : Debug:  Module: Instantiating module "exec" from
file /usr/local/etc/raddb/modules/exec

Fri Aug  2 16:45:25 2013 : Debug:   exec {

Fri Aug  2 16:45:25 2013 : Debug: wait = no

Fri Aug  2 16:45:25 2013 : Debug: input_pairs = "request"

Fri Aug  2 16:45:25 2013 : Debug: shell_escape = yes

Fri Aug  2 16:45:25 2013 : Debug:   }

Fri Aug  2 16:45:25 2013 : Debug:     (Loaded rlm_expr, checking if it's
valid)

Fri Aug  2 16:45:25 2013 : Debug:  Module: Linked to module rlm_expr

Fri Aug  2 16:45:25 2013 : Debug:  Module: Instantiating module "expr" from
file /usr/local/etc/raddb/modules/expr

Fri Aug  2 16:45:25 2013 : Debug:     (Loaded rlm_expiration, checking if
it's valid)

Fri Aug  2 16:45:25 2013 : Debug:  Module: Linked to module rlm_expiration

Fri Aug  2 16:45:25 2013 : Debug:  Module: Instantiating module
"expiration" from file /usr/local/etc/raddb/modules/expiration

Fri Aug  2 16:45:25 2013 : Debug:   expiration {

Fri Aug  2 16:45:25 2013 : Debug: reply-message = "Password Has Expired  "

Fri Aug  2 16:45:25 2013 : Debug:   }

Fri Aug  2 16:45:25 2013 : Debug:     (Loaded rlm_logintime, checking if
it's valid)

Fri Aug  2 16:45:25 2013 : Debug:  Module: Linked to module rlm_logintime

Fri Aug  2 16:45:25 2013 : Debug:  Module: Instantiating module "logintime"
from file /usr/local/etc/raddb/modules/logintime

Fri Aug  2 16:45:25 2013 : Debug:   logintime {

Fri Aug  2 16:45:25 2013 : Debug: reply-message = "You are calling outside
your allowed timespan  "

Fri Aug  2 16:45:25 2013 : Debug: minimum-timeout = 60

Fri Aug  2 16:45:25 2013 : Debug:   }

Fri Aug  2 16:45:25 2013 : Debug:  }

Fri Aug  2 16:45:25 2013 : Debug: radiusd: #### Loading Virtual Servers ####

Fri Aug  2 16:45:25 2013 : Debug: server { # from file
/usr/local/etc/raddb/radiusd.conf

Fri Aug  2 16:45:25 2013 : Debug:  modules {

Fri Aug  2 16:45:25 2013 : Debug:   Module: Creating Auth-Type = digest

Fri Aug  2 16:45:25 2013 : Debug:   Module: Creating Post-Auth-Type = REJECT

Fri Aug  2 16:45:25 2013 : Debug:  Module: Checking authenticate {...} for
more modules to load

Fri Aug  2 16:45:25 2013 : Debug:     (Loaded rlm_pap, checking if it's
valid)

Fri Aug  2 16:45:25 2013 : Debug:  Module: Linked to module rlm_pap

Fri Aug  2 16:45:25 2013 : Debug:  Module: Instantiating module "pap" from
file /usr/local/etc/raddb/modules/pap

Fri Aug  2 16:45:25 2013 : Debug:   pap {

Fri Aug  2 16:45:25 2013 : Debug: encryption_scheme = "auto"

Fri Aug  2 16:45:25 2013 : Debug: auto_header = no

Fri Aug  2 16:45:25 2013 : Debug:   }

Fri Aug  2 16:45:25 2013 : Debug:     (Loaded rlm_chap, checking if it's
valid)

Fri Aug  2 16:45:25 2013 : Debug:  Module: Linked to module rlm_chap

Fri Aug  2 16:45:25 2013 : Debug:  Module: Instantiating module "chap" from
file /usr/local/etc/raddb/modules/chap

Fri Aug  2 16:45:25 2013 : Debug:     (Loaded rlm_mschap, checking if it's
valid)

Fri Aug  2 16:45:25 2013 : Debug:  Module: Linked to module rlm_mschap

Fri Aug  2 16:45:25 2013 : Debug:  Module: Instantiating module "mschap"
from file /usr/local/etc/raddb/modules/mschap

Fri Aug  2 16:45:25 2013 : Debug:   mschap {

Fri Aug  2 16:45:25 2013 : Debug: use_mppe = yes

Fri Aug  2 16:45:25 2013 : Debug: require_encryption = no

Fri Aug  2 16:45:25 2013 : Debug: require_strong = no

Fri Aug  2 16:45:25 2013 : Debug: with_ntdomain_hack = no

Fri Aug  2 16:45:25 2013 : Debug: allow_retry = yes

Fri Aug  2 16:45:25 2013 : Debug:   }

Fri Aug  2 16:45:25 2013 : Debug:     (Loaded rlm_digest, checking if it's
valid)

Fri Aug  2 16:45:25 2013 : Debug:  Module: Linked to module rlm_digest

Fri Aug  2 16:45:25 2013 : Debug:  Module: Instantiating module "digest"
from file /usr/local/etc/raddb/modules/digest

Fri Aug  2 16:45:25 2013 : Debug:     (Loaded rlm_unix, checking if it's
valid)

Fri Aug  2 16:45:25 2013 : Debug:  Module: Linked to module rlm_unix

Fri Aug  2 16:45:25 2013 : Debug:  Module: Instantiating module "unix" from
file /usr/local/etc/raddb/modules/unix

Fri Aug  2 16:45:25 2013 : Debug:   unix {

Fri Aug  2 16:45:25 2013 : Debug: radwtmp =
"/usr/local/var/log/radius/radwtmp"

Fri Aug  2 16:45:25 2013 : Debug:   }

Fri Aug  2 16:45:25 2013 : Debug:     (Loaded rlm_eap, checking if it's
valid)

Fri Aug  2 16:45:25 2013 : Debug:  Module: Linked to module rlm_eap

Fri Aug  2 16:45:25 2013 : Debug:  Module: Instantiating module "eap" from
file /usr/local/etc/raddb/eap.conf

Fri Aug  2 16:45:25 2013 : Debug:   eap {

Fri Aug  2 16:45:25 2013 : Debug: default_eap_type = "md5"

Fri Aug  2 16:45:25 2013 : Debug: timer_expire = 60

Fri Aug  2 16:45:25 2013 : Debug: ignore_unknown_eap_types = no

Fri Aug  2 16:45:25 2013 : Debug: cisco_accounting_username_bug = no

Fri Aug  2 16:45:25 2013 : Debug: max_sessions = 4096

Fri Aug  2 16:45:25 2013 : Debug:   }

Fri Aug  2 16:45:25 2013 : Debug:  Module: Linked to sub-module rlm_eap_md5

Fri Aug  2 16:45:25 2013 : Debug:  Module: Instantiating eap-md5

Fri Aug  2 16:45:25 2013 : Debug:  Module: Linked to sub-module rlm_eap_leap

Fri Aug  2 16:45:25 2013 : Debug:  Module: Instantiating eap-leap

Fri Aug  2 16:45:25 2013 : Debug:  Module: Linked to sub-module rlm_eap_gtc

Fri Aug  2 16:45:25 2013 : Debug:  Module: Instantiating eap-gtc

Fri Aug  2 16:45:25 2013 : Debug:    gtc {

Fri Aug  2 16:45:25 2013 : Debug: challenge = "Password: "

Fri Aug  2 16:45:25 2013 : Debug: auth_type = "PAP"

Fri Aug  2 16:45:25 2013 : Debug:    }

Fri Aug  2 16:45:25 2013 : Debug:  Module: Linked to sub-module rlm_eap_tls

Fri Aug  2 16:45:25 2013 : Debug:  Module: Instantiating eap-tls

Fri Aug  2 16:45:25 2013 : Debug:    tls {

Fri Aug  2 16:45:25 2013 : Debug: rsa_key_exchange = no

Fri Aug  2 16:45:25 2013 : Debug: dh_key_exchange = yes

Fri Aug  2 16:45:25 2013 : Debug: rsa_key_length = 512

Fri Aug  2 16:45:25 2013 : Debug: dh_key_length = 512

Fri Aug  2 16:45:25 2013 : Debug: verify_depth = 0

Fri Aug  2 16:45:25 2013 : Debug: CA_path = "/usr/local/etc/raddb/certs"

Fri Aug  2 16:45:25 2013 : Debug: pem_file_type = yes

Fri Aug  2 16:45:25 2013 : Debug: private_key_file =
"/usr/local/etc/raddb/certs/server.pem"

Fri Aug  2 16:45:25 2013 : Debug: certificate_file =
"/usr/local/etc/raddb/certs/server.pem"

Fri Aug  2 16:45:25 2013 : Debug: CA_file =
"/usr/local/etc/raddb/certs/ca.pem"

Fri Aug  2 16:45:25 2013 : Debug: private_key_password = "whatever"

Fri Aug  2 16:45:25 2013 : Debug: dh_file = "/usr/local/etc/raddb/certs/dh"

Fri Aug  2 16:45:25 2013 : Debug: random_file =
"/usr/local/etc/raddb/certs/random"

Fri Aug  2 16:45:25 2013 : Debug: fragment_size = 1024

Fri Aug  2 16:45:25 2013 : Debug: include_length = yes

Fri Aug  2 16:45:25 2013 : Debug: check_crl = no

Fri Aug  2 16:45:25 2013 : Debug: cipher_list = "DEFAULT"

Fri Aug  2 16:45:25 2013 : Debug: make_cert_command =
"/usr/local/etc/raddb/certs/bootstrap"

Fri Aug  2 16:45:25 2013 : Debug:     cache {

Fri Aug  2 16:45:25 2013 : Debug: enable = no

Fri Aug  2 16:45:25 2013 : Debug: lifetime = 24

Fri Aug  2 16:45:25 2013 : Debug: max_entries = 255

Fri Aug  2 16:45:25 2013 : Debug:     }

Fri Aug  2 16:45:25 2013 : Debug:     verify {

Fri Aug  2 16:45:25 2013 : Debug:     }

Fri Aug  2 16:45:25 2013 : Debug:     ocsp {

Fri Aug  2 16:45:25 2013 : Debug: enable = no

Fri Aug  2 16:45:25 2013 : Debug: override_cert_url = yes

Fri Aug  2 16:45:25 2013 : Debug: url = "http://127.0.0.1/ocsp/"

Fri Aug  2 16:45:25 2013 : Debug: use_nonce = yes

Fri Aug  2 16:45:25 2013 : Debug: timeout = 0

Fri Aug  2 16:45:25 2013 : Debug: softfail = no

Fri Aug  2 16:45:25 2013 : Debug:     }

Fri Aug  2 16:45:25 2013 : Debug:    }

Fri Aug  2 16:45:25 2013 : Debug:  Module: Linked to sub-module rlm_eap_ttls

Fri Aug  2 16:45:25 2013 : Debug:  Module: Instantiating eap-ttls

Fri Aug  2 16:45:25 2013 : Debug:    ttls {

Fri Aug  2 16:45:25 2013 : Debug: default_eap_type = "md5"

Fri Aug  2 16:45:25 2013 : Debug: copy_request_to_tunnel = no

Fri Aug  2 16:45:25 2013 : Debug: use_tunneled_reply = no

Fri Aug  2 16:45:25 2013 : Debug: virtual_server = "inner-tunnel"

Fri Aug  2 16:45:25 2013 : Debug: include_length = yes

Fri Aug  2 16:45:25 2013 : Debug:    }

Fri Aug  2 16:45:25 2013 : Debug:  Module: Linked to sub-module rlm_eap_peap

Fri Aug  2 16:45:25 2013 : Debug:  Module: Instantiating eap-peap

Fri Aug  2 16:45:25 2013 : Debug:    peap {

Fri Aug  2 16:45:25 2013 : Debug: default_eap_type = "mschapv2"

Fri Aug  2 16:45:25 2013 : Debug: copy_request_to_tunnel = no

Fri Aug  2 16:45:25 2013 : Debug: use_tunneled_reply = no

Fri Aug  2 16:45:25 2013 : Debug: proxy_tunneled_request_as_eap = yes

Fri Aug  2 16:45:25 2013 : Debug: virtual_server = "inner-tunnel"

Fri Aug  2 16:45:25 2013 : Debug: soh = no

Fri Aug  2 16:45:25 2013 : Debug:    }

Fri Aug  2 16:45:25 2013 : Debug:  Module: Linked to sub-module
rlm_eap_mschapv2

Fri Aug  2 16:45:25 2013 : Debug:  Module: Instantiating eap-mschapv2

Fri Aug  2 16:45:25 2013 : Debug:    mschapv2 {

Fri Aug  2 16:45:25 2013 : Debug: with_ntdomain_hack = no

Fri Aug  2 16:45:25 2013 : Debug: send_error = no

Fri Aug  2 16:45:25 2013 : Debug:    }

Fri Aug  2 16:45:25 2013 : Debug:  Module: Checking authorize {...} for
more modules to load

Fri Aug  2 16:45:25 2013 : Debug:     (Loaded rlm_preprocess, checking if
it's valid)

Fri Aug  2 16:45:25 2013 : Debug:  Module: Linked to module rlm_preprocess

Fri Aug  2 16:45:25 2013 : Debug:  Module: Instantiating module
"preprocess" from file /usr/local/etc/raddb/modules/preprocess

Fri Aug  2 16:45:25 2013 : Debug:   preprocess {

Fri Aug  2 16:45:25 2013 : Debug: huntgroups =
"/usr/local/etc/raddb/huntgroups"

Fri Aug  2 16:45:25 2013 : Debug: hints = "/usr/local/etc/raddb/hints"

Fri Aug  2 16:45:25 2013 : Debug: with_ascend_hack = no

Fri Aug  2 16:45:25 2013 : Debug: ascend_channels_per_line = 23

Fri Aug  2 16:45:25 2013 : Debug: with_ntdomain_hack = no

Fri Aug  2 16:45:25 2013 : Debug: with_specialix_jetstream_hack = no

Fri Aug  2 16:45:25 2013 : Debug: with_cisco_vsa_hack = no

Fri Aug  2 16:45:25 2013 : Debug: with_alvarion_vsa_hack = no

Fri Aug  2 16:45:25 2013 : Debug:   }

Fri Aug  2 16:45:25 2013 : Debug: reading pairlist file
/usr/local/etc/raddb/huntgroups

Fri Aug  2 16:45:25 2013 : Debug: reading pairlist file
/usr/local/etc/raddb/hints

Fri Aug  2 16:45:25 2013 : Debug:     (Loaded rlm_realm, checking if it's
valid)

Fri Aug  2 16:45:25 2013 : Debug:  Module: Linked to module rlm_realm

Fri Aug  2 16:45:25 2013 : Debug:  Module: Instantiating module "suffix"
from file /usr/local/etc/raddb/modules/realm

Fri Aug  2 16:45:25 2013 : Debug:   realm suffix {

Fri Aug  2 16:45:25 2013 : Debug: format = "suffix"

Fri Aug  2 16:45:25 2013 : Debug: delimiter = "@"

Fri Aug  2 16:45:25 2013 : Debug: ignore_default = no

Fri Aug  2 16:45:25 2013 : Debug: ignore_null = no

Fri Aug  2 16:45:25 2013 : Debug:   }

Fri Aug  2 16:45:25 2013 : Debug:  Module: Checking preacct {...} for more
modules to load

Fri Aug  2 16:45:25 2013 : Debug:     (Loaded rlm_acct_unique, checking if
it's valid)

Fri Aug  2 16:45:25 2013 : Debug:  Module: Linked to module rlm_acct_unique

Fri Aug  2 16:45:25 2013 : Debug:  Module: Instantiating module
"acct_unique" from file /usr/local/etc/raddb/modules/acct_unique

Fri Aug  2 16:45:25 2013 : Debug:   acct_unique {

Fri Aug  2 16:45:25 2013 : Debug: key = "User-Name, Acct-Session-Id,
NAS-IP-Address, NAS-Identifier, NAS-Port"

Fri Aug  2 16:45:25 2013 : Debug:   }

Fri Aug  2 16:45:25 2013 : Debug:     (Loaded rlm_files, checking if it's
valid)

Fri Aug  2 16:45:25 2013 : Debug:  Module: Linked to module rlm_files

Fri Aug  2 16:45:25 2013 : Debug:  Module: Instantiating module "files"
from file /usr/local/etc/raddb/modules/files

Fri Aug  2 16:45:25 2013 : Debug:   files {

Fri Aug  2 16:45:25 2013 : Debug: usersfile = "/usr/local/etc/raddb/users"

Fri Aug  2 16:45:25 2013 : Debug: acctusersfile =
"/usr/local/etc/raddb/acct_users"

Fri Aug  2 16:45:25 2013 : Debug: preproxy_usersfile =
"/usr/local/etc/raddb/preproxy_users"

Fri Aug  2 16:45:25 2013 : Debug: compat = "no"

Fri Aug  2 16:45:25 2013 : Debug:   }

Fri Aug  2 16:45:25 2013 : Debug: reading pairlist file
/usr/local/etc/raddb/users

Fri Aug  2 16:45:25 2013 : Debug: reading pairlist file
/usr/local/etc/raddb/acct_users

Fri Aug  2 16:45:25 2013 : Debug: reading pairlist file
/usr/local/etc/raddb/preproxy_users

Fri Aug  2 16:45:25 2013 : Debug:  Module: Checking accounting {...} for
more modules to load

Fri Aug  2 16:45:25 2013 : Debug:     (Loaded rlm_detail, checking if it's
valid)

Fri Aug  2 16:45:25 2013 : Debug:  Module: Linked to module rlm_detail

Fri Aug  2 16:45:25 2013 : Debug:  Module: Instantiating module "detail"
from file /usr/local/etc/raddb/modules/detail

Fri Aug  2 16:45:25 2013 : Debug:   detail {

Fri Aug  2 16:45:25 2013 : Debug: detailfile =
"/usr/local/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d"

Fri Aug  2 16:45:25 2013 : Debug: header = "%t"

Fri Aug  2 16:45:25 2013 : Debug: detailperm = 384

Fri Aug  2 16:45:25 2013 : Debug: dirperm = 493

Fri Aug  2 16:45:25 2013 : Debug: locking = no

Fri Aug  2 16:45:25 2013 : Debug: log_packet_header = no

Fri Aug  2 16:45:25 2013 : Debug:   }

Fri Aug  2 16:45:25 2013 : Debug:     (Loaded rlm_attr_filter, checking if
it's valid)

Fri Aug  2 16:45:25 2013 : Debug:  Module: Linked to module rlm_attr_filter

Fri Aug  2 16:45:25 2013 : Debug:  Module: Instantiating module
"attr_filter.accounting_response" from file
/usr/local/etc/raddb/modules/attr_filter

Fri Aug  2 16:45:25 2013 : Debug:   attr_filter
attr_filter.accounting_response {

Fri Aug  2 16:45:25 2013 : Debug: attrsfile =
"/usr/local/etc/raddb/attrs.accounting_response"

Fri Aug  2 16:45:25 2013 : Debug: key = "%{User-Name}"

Fri Aug  2 16:45:25 2013 : Debug: relaxed = no

Fri Aug  2 16:45:25 2013 : Debug:   }

Fri Aug  2 16:45:25 2013 : Debug: reading pairlist file
/usr/local/etc/raddb/attrs.accounting_response

Fri Aug  2 16:45:25 2013 : Debug:  Module: Checking session {...} for more
modules to load

Fri Aug  2 16:45:25 2013 : Debug:     (Loaded rlm_radutmp, checking if it's
valid)

Fri Aug  2 16:45:25 2013 : Debug:  Module: Linked to module rlm_radutmp

Fri Aug  2 16:45:25 2013 : Debug:  Module: Instantiating module "radutmp"
from file /usr/local/etc/raddb/modules/radutmp

Fri Aug  2 16:45:25 2013 : Debug:   radutmp {

Fri Aug  2 16:45:25 2013 : Debug: filename =
"/usr/local/var/log/radius/radutmp"

Fri Aug  2 16:45:25 2013 : Debug: username = "%{User-Name}"

Fri Aug  2 16:45:25 2013 : Debug: case_sensitive = yes

Fri Aug  2 16:45:25 2013 : Debug: check_with_nas = yes

Fri Aug  2 16:45:25 2013 : Debug: perm = 384

Fri Aug  2 16:45:25 2013 : Debug: callerid = yes

Fri Aug  2 16:45:25 2013 : Debug:   }

Fri Aug  2 16:45:25 2013 : Debug:  Module: Checking post-auth {...} for
more modules to load

Fri Aug  2 16:45:25 2013 : Debug:  Module: Instantiating module
"attr_filter.access_reject" from file
/usr/local/etc/raddb/modules/attr_filter

Fri Aug  2 16:45:25 2013 : Debug:   attr_filter attr_filter.access_reject {

Fri Aug  2 16:45:25 2013 : Debug: attrsfile =
"/usr/local/etc/raddb/attrs.access_reject"

Fri Aug  2 16:45:25 2013 : Debug: key = "%{User-Name}"

Fri Aug  2 16:45:25 2013 : Debug: relaxed = no

Fri Aug  2 16:45:25 2013 : Debug:   }

Fri Aug  2 16:45:25 2013 : Debug: reading pairlist file
/usr/local/etc/raddb/attrs.access_reject

Fri Aug  2 16:45:25 2013 : Debug:  } # modules

Fri Aug  2 16:45:25 2013 : Debug: } # server

Fri Aug  2 16:45:25 2013 : Debug: server inner-tunnel { # from file
/usr/local/etc/raddb/sites-enabled/inner-tunnel

Fri Aug  2 16:45:25 2013 : Debug:  modules {

Fri Aug  2 16:45:25 2013 : Debug:  Module: Checking authenticate {...} for
more modules to load

Fri Aug  2 16:45:25 2013 : Debug:  Module: Checking authorize {...} for
more modules to load

Fri Aug  2 16:45:25 2013 : Debug:  Module: Checking session {...} for more
modules to load

Fri Aug  2 16:45:25 2013 : Debug:  Module: Checking post-proxy {...} for
more modules to load

Fri Aug  2 16:45:25 2013 : Debug:  Module: Checking post-auth {...} for
more modules to load

Fri Aug  2 16:45:25 2013 : Debug:  } # modules

Fri Aug  2 16:45:25 2013 : Debug: } # server

Fri Aug  2 16:45:25 2013 : Debug: radiusd: #### Opening IP addresses and
Ports ####

Fri Aug  2 16:45:25 2013 : Debug: listen {

Fri Aug  2 16:45:25 2013 : Debug: type = "auth"

Fri Aug  2 16:45:25 2013 : Debug: ipaddr = 10.100.111.3

Fri Aug  2 16:45:25 2013 : Debug: port = 0

Fri Aug  2 16:45:25 2013 : Debug: }

Fri Aug  2 16:45:25 2013 : Debug: listen {

Fri Aug  2 16:45:25 2013 : Debug: type = "acct"

Fri Aug  2 16:45:25 2013 : Debug: ipaddr = 10.100.111.3

Fri Aug  2 16:45:25 2013 : Debug: port = 0

Fri Aug  2 16:45:25 2013 : Debug: }

Fri Aug  2 16:45:25 2013 : Debug: listen {

Fri Aug  2 16:45:25 2013 : Debug: type = "control"

Fri Aug  2 16:45:25 2013 : Debug:  listen {

Fri Aug  2 16:45:25 2013 : Debug: socket =
"/usr/local/var/run/radiusd/radiusd.sock"

Fri Aug  2 16:45:25 2013 : Debug:  }

Fri Aug  2 16:45:25 2013 : Debug: }

Fri Aug  2 16:45:25 2013 : Debug: listen {

Fri Aug  2 16:45:25 2013 : Debug: type = "auth"

Fri Aug  2 16:45:25 2013 : Debug: ipaddr = 127.0.0.1

Fri Aug  2 16:45:25 2013 : Debug: port = 18120

Fri Aug  2 16:45:25 2013 : Debug: }

Fri Aug  2 16:45:25 2013 : Debug: Listening on authentication address
10.100.111.3 port 1812

Fri Aug  2 16:45:25 2013 : Debug: Listening on accounting interface eth1
address 10.100.111.3 port 1813

Fri Aug  2 16:45:25 2013 : Debug: Listening on command file
/usr/local/var/run/radiusd/radiusd.sock

Fri Aug  2 16:45:25 2013 : Debug: Listening on authentication address
127.0.0.1 port 18120 as server inner-tunnel

Fri Aug  2 16:45:25 2013 : Info: Ready to process requests.

rad_recv: Access-Request packet from host 10.100.111.2 port 4061, id=60,
length=77

User-Name = "rajeev"

User-Password = "\334a\004\305\355x\321\332G\306\362b\226~\355+"

NAS-IP-Address = 135.250.14.111

NAS-Identifier = "login"

NAS-Port = 3036

NAS-Port-Type = Virtual

Service-Type = Authenticate-Only

Fri Aug  2 16:45:38 2013 : Info: # Executing section authorize from file
/usr/local/etc/raddb/sites-enabled/default

Fri Aug  2 16:45:38 2013 : Info: +- entering group authorize {...}

Fri Aug  2 16:45:38 2013 : Info: ++[preprocess] returns ok

Fri Aug  2 16:45:38 2013 : Info: [suffix] No '@' in User-Name = "rajeev",
looking up realm NULL

Fri Aug  2 16:45:38 2013 : Info: [suffix] No such realm "NULL"

Fri Aug  2 16:45:38 2013 : Info: ++[suffix] returns noop

Fri Aug  2 16:45:38 2013 : Info: ++[expiration] returns noop

Fri Aug  2 16:45:38 2013 : Info: ++[logintime] returns noop

Fri Aug  2 16:45:38 2013 : Info: [pap] WARNING! No "known good" password
found for the user.  Authentication may fail because of this.

Fri Aug  2 16:45:38 2013 : Info: ++[pap] returns noop

Fri Aug  2 16:45:38 2013 : Info: ERROR: No authenticate method (Auth-Type)
found for the request: Rejecting the user

Fri Aug  2 16:45:38 2013 : Info: Failed to authenticate the user.

Fri Aug  2 16:45:38 2013 : Debug:   WARNING: Unprintable characters in the
password.  Double-check the shared secret on the server and the NAS!

Fri Aug  2 16:45:38 2013 : Info: Using Post-Auth-Type REJECT

Fri Aug  2 16:45:38 2013 : Info: # Executing group from file
/usr/local/etc/raddb/sites-enabled/default

Fri Aug  2 16:45:38 2013 : Info: +- entering group REJECT {...}

Fri Aug  2 16:45:38 2013 : Info: [attr_filter.access_reject] expand:
%{User-Name} -> rajeev

Fri Aug  2 16:45:38 2013 : Debug: attr_filter: Matched entry DEFAULT at
line 11

Fri Aug  2 16:45:38 2013 : Info: ++[attr_filter.access_reject] returns
updated

Fri Aug  2 16:45:38 2013 : Info: Delaying reject of request 0 for 1 seconds

Fri Aug  2 16:45:38 2013 : Debug: Going to the next request

Fri Aug  2 16:45:38 2013 : Debug: Waking up in 0.9 seconds.

Fri Aug  2 16:45:39 2013 : Info: Sending delayed reject for request 0

Sending Access-Reject of id 60 to 10.100.111.2 port 4061

Fri Aug  2 16:45:39 2013 : Debug: Waking up in 4.9 seconds.

Fri Aug  2 16:45:44 2013 : Info: Cleaning up request 0 ID 60 with timestamp
+13

Fri Aug  2 16:45:44 2013 : Info: Ready to process requests.

^C

]0;root@radioserver:/usr/local/etc/raddb [root@radioserver raddb]#

Br,

Rajeev

Freeradius -username for authentication is not picking from users file.

rajeev sr