Hi, I am having strange behavior of rlm_expiration where it always returns "userlock", no matter what I put as expiration value. my radius install is latest from git repository, with default configuration (unchanged in any way), rlm_expiration rejects this user, date "10 Jan 2009", although it should be accepted... could somebody confirm working rlm_expiration on latest sources ? home raddb # cat users a Cleartext-Password := a, Expiration := "10 Jan 2009" Reply-Message = "ok" home raddb # ../../sbin/radiusd -XX Wed Oct 1 11:22:37 2008 : Info: FreeRADIUS Version 2.1.1, for host i686-pc-linux-gnu, built on Oct 1 2008 at 21:32:48 Wed Oct 1 11:22:37 2008 : Info: Copyright (C) 1999-2008 The FreeRADIUS server project and contributors. Wed Oct 1 11:22:37 2008 : Info: There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A Wed Oct 1 11:22:37 2008 : Info: PARTICULAR PURPOSE. Wed Oct 1 11:22:37 2008 : Info: You may redistribute copies of FreeRADIUS under the terms of the Wed Oct 1 11:22:37 2008 : Info: GNU General Public License v2. Wed Oct 1 11:22:37 2008 : Info: Starting - reading configuration files ... Wed Oct 1 11:22:37 2008 : Debug: including configuration file /home/radius2.11/etc/raddb/radiusd.conf Wed Oct 1 11:22:37 2008 : Debug: including configuration file /home/radius2.11/etc/raddb/proxy.conf Wed Oct 1 11:22:37 2008 : Debug: including configuration file /home/radius2.11/etc/raddb/clients.conf Wed Oct 1 11:22:37 2008 : Debug: including files in directory /home/radius2.11/etc/raddb/modules/ Wed Oct 1 11:22:37 2008 : Debug: including configuration file /home/radius2.11/etc/raddb/modules/radutmp Wed Oct 1 11:22:37 2008 : Debug: including configuration file /home/radius2.11/etc/raddb/modules/pap Wed Oct 1 11:22:37 2008 : Debug: including configuration file /home/radius2.11/etc/raddb/modules/logintime Wed Oct 1 11:22:37 2008 : Debug: including configuration file /home/radius2.11/etc/raddb/modules/detail Wed Oct 1 11:22:37 2008 : Debug: including configuration file /home/radius2.11/etc/raddb/modules/realm Wed Oct 1 11:22:37 2008 : Debug: including configuration file /home/radius2.11/etc/raddb/modules/acct_unique Wed Oct 1 11:22:37 2008 : Debug: including configuration file /home/radius2.11/etc/raddb/modules/expr Wed Oct 1 11:22:37 2008 : Debug: including configuration file /home/radius2.11/etc/raddb/modules/mac2vlan Wed Oct 1 11:22:37 2008 : Debug: including configuration file /home/radius2.11/etc/raddb/modules/files Wed Oct 1 11:22:37 2008 : Debug: including configuration file /home/radius2.11/etc/raddb/modules/echo Wed Oct 1 11:22:37 2008 : Debug: including configuration file /home/radius2.11/etc/raddb/modules/mschap Wed Oct 1 11:22:37 2008 : Debug: including configuration file /home/radius2.11/etc/raddb/modules/preprocess Wed Oct 1 11:22:37 2008 : Debug: including configuration file /home/radius2.11/etc/raddb/modules/krb5 Wed Oct 1 11:22:37 2008 : Debug: including configuration file /home/radius2.11/etc/raddb/modules/pam Wed Oct 1 11:22:37 2008 : Debug: including configuration file /home/radius2.11/etc/raddb/modules/attr_rewrite Wed Oct 1 11:22:37 2008 : Debug: including configuration file /home/radius2.11/etc/raddb/modules/smbpasswd Wed Oct 1 11:22:37 2008 : Debug: including configuration file /home/radius2.11/etc/raddb/modules/policy Wed Oct 1 11:22:37 2008 : Debug: including configuration file /home/radius2.11/etc/raddb/modules/ldap Wed Oct 1 11:22:37 2008 : Debug: including configuration file /home/radius2.11/etc/raddb/modules/wimax Wed Oct 1 11:22:37 2008 : Debug: including configuration file /home/radius2.11/etc/raddb/modules/attr_filter Wed Oct 1 11:22:37 2008 : Debug: including configuration file /home/radius2.11/etc/raddb/modules/detail.log Wed Oct 1 11:22:37 2008 : Debug: including configuration file /home/radius2.11/etc/raddb/modules/mac2ip Wed Oct 1 11:22:37 2008 : Debug: including configuration file /home/radius2.11/etc/raddb/modules/always Wed Oct 1 11:22:37 2008 : Debug: including configuration file /home/radius2.11/etc/raddb/modules/sradutmp Wed Oct 1 11:22:37 2008 : Debug: including configuration file /home/radius2.11/etc/raddb/modules/checkval Wed Oct 1 11:22:37 2008 : Debug: including configuration file /home/radius2.11/etc/raddb/modules/inner-eap Wed Oct 1 11:22:37 2008 : Debug: including configuration file /home/radius2.11/etc/raddb/modules/detail.example.com Wed Oct 1 11:22:37 2008 : Debug: including configuration file /home/radius2.11/etc/raddb/modules/exec Wed Oct 1 11:22:37 2008 : Debug: including configuration file /home/radius2.11/etc/raddb/modules/passwd Wed Oct 1 11:22:37 2008 : Debug: including configuration file /home/radius2.11/etc/raddb/modules/digest Wed Oct 1 11:22:37 2008 : Debug: including configuration file /home/radius2.11/etc/raddb/modules/chap Wed Oct 1 11:22:37 2008 : Debug: including configuration file /home/radius2.11/etc/raddb/modules/linelog Wed Oct 1 11:22:37 2008 : Debug: including configuration file /home/radius2.11/etc/raddb/modules/etc_group Wed Oct 1 11:22:37 2008 : Debug: including configuration file /home/radius2.11/etc/raddb/modules/ippool Wed Oct 1 11:22:37 2008 : Debug: including configuration file /home/radius2.11/etc/raddb/modules/sql_log Wed Oct 1 11:22:37 2008 : Debug: including configuration file /home/radius2.11/etc/raddb/modules/counter Wed Oct 1 11:22:37 2008 : Debug: including configuration file /home/radius2.11/etc/raddb/modules/unix Wed Oct 1 11:22:37 2008 : Debug: including configuration file /home/radius2.11/etc/raddb/modules/expiration Wed Oct 1 11:22:37 2008 : Debug: including configuration file /home/radius2.11/etc/raddb/eap.conf Wed Oct 1 11:22:37 2008 : Debug: including configuration file /home/radius2.11/etc/raddb/sql.conf Wed Oct 1 11:22:37 2008 : Debug: including configuration file /home/radius2.11/etc/raddb/sql/mysql/dialup.conf Wed Oct 1 11:22:37 2008 : Debug: including configuration file /home/radius2.11/etc/raddb/sql/mysql/counter.conf Wed Oct 1 11:22:37 2008 : Debug: including configuration file /home/radius2.11/etc/raddb/policy.conf Wed Oct 1 11:22:37 2008 : Debug: including files in directory /home/radius2.11/etc/raddb/sites-enabled/ Wed Oct 1 11:22:37 2008 : Debug: including configuration file /home/radius2.11/etc/raddb/sites-enabled/default Wed Oct 1 11:22:37 2008 : Debug: including configuration file /home/radius2.11/etc/raddb/sites-enabled/inner-tunnel Wed Oct 1 11:22:37 2008 : Debug: including dictionary file /home/radius2.11/etc/raddb/dictionary Wed Oct 1 11:22:37 2008 : Debug: main { Wed Oct 1 11:22:37 2008 : Debug: prefix = "/home/radius2.11" Wed Oct 1 11:22:37 2008 : Debug: localstatedir = "/home/radius2.11/var" Wed Oct 1 11:22:37 2008 : Debug: logdir = "/home/radius2.11/var/log/radius" Wed Oct 1 11:22:37 2008 : Debug: libdir = "/home/radius2.11/lib" Wed Oct 1 11:22:37 2008 : Debug: radacctdir = "/home/radius2.11/var/log/radius/radacct" Wed Oct 1 11:22:37 2008 : Debug: hostname_lookups = no Wed Oct 1 11:22:37 2008 : Debug: max_request_time = 30 Wed Oct 1 11:22:37 2008 : Debug: cleanup_delay = 5 Wed Oct 1 11:22:37 2008 : Debug: max_requests = 1024 Wed Oct 1 11:22:37 2008 : Debug: allow_core_dumps = no Wed Oct 1 11:22:37 2008 : Debug: pidfile = "/home/radius2.11/var/run/radiusd/radiusd.pid" Wed Oct 1 11:22:37 2008 : Debug: checkrad = "/home/radius2.11/sbin/checkrad" Wed Oct 1 11:22:37 2008 : Debug: debug_level = 0 Wed Oct 1 11:22:37 2008 : Debug: proxy_requests = yes Wed Oct 1 11:22:37 2008 : Debug: log { Wed Oct 1 11:22:37 2008 : Debug: stripped_names = no Wed Oct 1 11:22:37 2008 : Debug: auth = no Wed Oct 1 11:22:37 2008 : Debug: auth_badpass = no Wed Oct 1 11:22:37 2008 : Debug: auth_goodpass = no Wed Oct 1 11:22:37 2008 : Debug: } Wed Oct 1 11:22:37 2008 : Debug: security { Wed Oct 1 11:22:37 2008 : Debug: max_attributes = 200 Wed Oct 1 11:22:37 2008 : Debug: reject_delay = 1 Wed Oct 1 11:22:37 2008 : Debug: status_server = yes Wed Oct 1 11:22:37 2008 : Debug: } Wed Oct 1 11:22:37 2008 : Debug: } Wed Oct 1 11:22:37 2008 : Debug: client localhost { Wed Oct 1 11:22:37 2008 : Debug: ipaddr = 127.0.0.1 Wed Oct 1 11:22:37 2008 : Debug: require_message_authenticator = no Wed Oct 1 11:22:37 2008 : Debug: secret = "testing123" Wed Oct 1 11:22:37 2008 : Debug: nastype = "other" Wed Oct 1 11:22:37 2008 : Debug: } Wed Oct 1 11:22:37 2008 : Debug: client 10.241.21.202 { Wed Oct 1 11:22:37 2008 : Debug: require_message_authenticator = no Wed Oct 1 11:22:37 2008 : Debug: secret = "testing123" Wed Oct 1 11:22:37 2008 : Debug: shortname = "winxp" Wed Oct 1 11:22:37 2008 : Debug: nastype = "other" Wed Oct 1 11:22:37 2008 : Debug: } Wed Oct 1 11:22:37 2008 : Debug: radiusd: #### Loading Realms and Home Servers #### Wed Oct 1 11:22:37 2008 : Debug: proxy server { Wed Oct 1 11:22:37 2008 : Debug: retry_delay = 5 Wed Oct 1 11:22:37 2008 : Debug: retry_count = 3 Wed Oct 1 11:22:37 2008 : Debug: default_fallback = no Wed Oct 1 11:22:37 2008 : Debug: dead_time = 120 Wed Oct 1 11:22:37 2008 : Debug: wake_all_if_all_dead = no Wed Oct 1 11:22:37 2008 : Debug: } Wed Oct 1 11:22:37 2008 : Debug: home_server localhost { Wed Oct 1 11:22:37 2008 : Debug: ipaddr = 127.0.0.1 Wed Oct 1 11:22:37 2008 : Debug: port = 1812 Wed Oct 1 11:22:37 2008 : Debug: type = "auth" Wed Oct 1 11:22:37 2008 : Debug: secret = "testing123" Wed Oct 1 11:22:37 2008 : Debug: response_window = 20 Wed Oct 1 11:22:37 2008 : Debug: max_outstanding = 65536 Wed Oct 1 11:22:37 2008 : Debug: zombie_period = 40 Wed Oct 1 11:22:37 2008 : Debug: status_check = "status-server" Wed Oct 1 11:22:37 2008 : Debug: ping_interval = 30 Wed Oct 1 11:22:37 2008 : Debug: check_interval = 30 Wed Oct 1 11:22:37 2008 : Debug: num_answers_to_alive = 3 Wed Oct 1 11:22:37 2008 : Debug: num_pings_to_alive = 3 Wed Oct 1 11:22:37 2008 : Debug: revive_interval = 120 Wed Oct 1 11:22:37 2008 : Debug: status_check_timeout = 4 Wed Oct 1 11:22:37 2008 : Debug: } Wed Oct 1 11:22:37 2008 : Debug: home_server_pool my_auth_failover { Wed Oct 1 11:22:37 2008 : Debug: type = fail-over Wed Oct 1 11:22:37 2008 : Debug: home_server = localhost Wed Oct 1 11:22:37 2008 : Debug: } Wed Oct 1 11:22:37 2008 : Debug: realm example.com { Wed Oct 1 11:22:37 2008 : Debug: auth_pool = my_auth_failover Wed Oct 1 11:22:37 2008 : Debug: } Wed Oct 1 11:22:37 2008 : Debug: realm LOCAL { Wed Oct 1 11:22:37 2008 : Debug: } Wed Oct 1 11:22:37 2008 : Debug: radiusd: #### Instantiating modules #### Wed Oct 1 11:22:37 2008 : Debug: instantiate { Wed Oct 1 11:22:37 2008 : Debug: (Loaded rlm_exec, checking if it's valid) Wed Oct 1 11:22:37 2008 : Debug: Module: Linked to module rlm_exec Wed Oct 1 11:22:37 2008 : Debug: Module: Instantiating exec Wed Oct 1 11:22:37 2008 : Debug: exec { Wed Oct 1 11:22:37 2008 : Debug: wait = no Wed Oct 1 11:22:37 2008 : Debug: input_pairs = "request" Wed Oct 1 11:22:37 2008 : Debug: shell_escape = yes Wed Oct 1 11:22:37 2008 : Debug: } Wed Oct 1 11:22:37 2008 : Debug: (Loaded rlm_expr, checking if it's valid) Wed Oct 1 11:22:37 2008 : Debug: Module: Linked to module rlm_expr Wed Oct 1 11:22:37 2008 : Debug: Module: Instantiating expr Wed Oct 1 11:22:37 2008 : Debug: (Loaded rlm_expiration, checking if it's valid) Wed Oct 1 11:22:37 2008 : Debug: Module: Linked to module rlm_expiration Wed Oct 1 11:22:37 2008 : Debug: Module: Instantiating expiration Wed Oct 1 11:22:37 2008 : Debug: expiration { Wed Oct 1 11:22:37 2008 : Debug: reply-message = "Password Has Expired " Wed Oct 1 11:22:37 2008 : Debug: } Wed Oct 1 11:22:37 2008 : Debug: (Loaded rlm_logintime, checking if it's valid) Wed Oct 1 11:22:37 2008 : Debug: Module: Linked to module rlm_logintime Wed Oct 1 11:22:37 2008 : Debug: Module: Instantiating logintime Wed Oct 1 11:22:37 2008 : Debug: logintime { Wed Oct 1 11:22:37 2008 : Debug: reply-message = "You are calling outside your allowed timespan " Wed Oct 1 11:22:37 2008 : Debug: minimum-timeout = 60 Wed Oct 1 11:22:37 2008 : Debug: } Wed Oct 1 11:22:37 2008 : Debug: } Wed Oct 1 11:22:37 2008 : Debug: radiusd: #### Loading Virtual Servers #### Wed Oct 1 11:22:37 2008 : Debug: server inner-tunnel { Wed Oct 1 11:22:37 2008 : Debug: modules { Wed Oct 1 11:22:37 2008 : Debug: Module: Checking authenticate {...} for more modules to load Wed Oct 1 11:22:37 2008 : Debug: (Loaded rlm_pap, checking if it's valid) Wed Oct 1 11:22:37 2008 : Debug: Module: Linked to module rlm_pap Wed Oct 1 11:22:37 2008 : Debug: Module: Instantiating pap Wed Oct 1 11:22:37 2008 : Debug: pap { Wed Oct 1 11:22:37 2008 : Debug: encryption_scheme = "auto" Wed Oct 1 11:22:37 2008 : Debug: auto_header = no Wed Oct 1 11:22:37 2008 : Debug: } Wed Oct 1 11:22:37 2008 : Debug: (Loaded rlm_chap, checking if it's valid) Wed Oct 1 11:22:37 2008 : Debug: Module: Linked to module rlm_chap Wed Oct 1 11:22:37 2008 : Debug: Module: Instantiating chap Wed Oct 1 11:22:37 2008 : Debug: (Loaded rlm_mschap, checking if it's valid) Wed Oct 1 11:22:37 2008 : Debug: Module: Linked to module rlm_mschap Wed Oct 1 11:22:37 2008 : Debug: Module: Instantiating mschap Wed Oct 1 11:22:37 2008 : Debug: mschap { Wed Oct 1 11:22:37 2008 : Debug: use_mppe = yes Wed Oct 1 11:22:37 2008 : Debug: require_encryption = no Wed Oct 1 11:22:37 2008 : Debug: require_strong = no Wed Oct 1 11:22:37 2008 : Debug: with_ntdomain_hack = no Wed Oct 1 11:22:37 2008 : Debug: } Wed Oct 1 11:22:37 2008 : Debug: (Loaded rlm_unix, checking if it's valid) Wed Oct 1 11:22:37 2008 : Debug: Module: Linked to module rlm_unix Wed Oct 1 11:22:37 2008 : Debug: Module: Instantiating unix Wed Oct 1 11:22:37 2008 : Debug: unix { Wed Oct 1 11:22:37 2008 : Debug: radwtmp = "/home/radius2.11/var/log/radius/radwtmp" Wed Oct 1 11:22:37 2008 : Debug: } Wed Oct 1 11:22:37 2008 : Debug: (Loaded rlm_eap, checking if it's valid) Wed Oct 1 11:22:37 2008 : Debug: Module: Linked to module rlm_eap Wed Oct 1 11:22:37 2008 : Debug: Module: Instantiating eap Wed Oct 1 11:22:37 2008 : Debug: eap { Wed Oct 1 11:22:37 2008 : Debug: default_eap_type = "md5" Wed Oct 1 11:22:37 2008 : Debug: timer_expire = 60 Wed Oct 1 11:22:37 2008 : Debug: ignore_unknown_eap_types = no Wed Oct 1 11:22:37 2008 : Debug: cisco_accounting_username_bug = no Wed Oct 1 11:22:37 2008 : Debug: max_sessions = 2048 Wed Oct 1 11:22:37 2008 : Debug: } Wed Oct 1 11:22:37 2008 : Debug: Module: Linked to sub-module rlm_eap_md5 Wed Oct 1 11:22:37 2008 : Debug: Module: Instantiating eap-md5 Wed Oct 1 11:22:37 2008 : Debug: Module: Linked to sub-module rlm_eap_leap Wed Oct 1 11:22:37 2008 : Debug: Module: Instantiating eap-leap Wed Oct 1 11:22:37 2008 : Debug: Module: Linked to sub-module rlm_eap_gtc Wed Oct 1 11:22:37 2008 : Debug: Module: Instantiating eap-gtc Wed Oct 1 11:22:37 2008 : Debug: gtc { Wed Oct 1 11:22:37 2008 : Debug: challenge = "Password: " Wed Oct 1 11:22:37 2008 : Debug: auth_type = "PAP" Wed Oct 1 11:22:37 2008 : Debug: } Wed Oct 1 11:22:37 2008 : Debug: Module: Linked to sub-module rlm_eap_tls Wed Oct 1 11:22:37 2008 : Debug: Module: Instantiating eap-tls Wed Oct 1 11:22:37 2008 : Debug: tls { Wed Oct 1 11:22:37 2008 : Debug: rsa_key_exchange = no Wed Oct 1 11:22:37 2008 : Debug: dh_key_exchange = yes Wed Oct 1 11:22:37 2008 : Debug: rsa_key_length = 512 Wed Oct 1 11:22:37 2008 : Debug: dh_key_length = 512 Wed Oct 1 11:22:37 2008 : Debug: verify_depth = 0 Wed Oct 1 11:22:37 2008 : Debug: pem_file_type = yes Wed Oct 1 11:22:37 2008 : Debug: private_key_file = "/home/radius2.11/etc/raddb/certs/server.pem" Wed Oct 1 11:22:37 2008 : Debug: certificate_file = "/home/radius2.11/etc/raddb/certs/server.pem" Wed Oct 1 11:22:37 2008 : Debug: CA_file = "/home/radius2.11/etc/raddb/certs/ca.pem" Wed Oct 1 11:22:37 2008 : Debug: private_key_password = "whatever" Wed Oct 1 11:22:37 2008 : Debug: dh_file = "/home/radius2.11/etc/raddb/certs/dh" Wed Oct 1 11:22:37 2008 : Debug: random_file = "/home/radius2.11/etc/raddb/certs/random" Wed Oct 1 11:22:37 2008 : Debug: fragment_size = 1024 Wed Oct 1 11:22:37 2008 : Debug: include_length = yes Wed Oct 1 11:22:37 2008 : Debug: check_crl = no Wed Oct 1 11:22:37 2008 : Debug: cipher_list = "DEFAULT" Wed Oct 1 11:22:37 2008 : Debug: make_cert_command = "/home/radius2.11/etc/raddb/certs/bootstrap" Wed Oct 1 11:22:37 2008 : Debug: cache { Wed Oct 1 11:22:37 2008 : Debug: enable = no Wed Oct 1 11:22:37 2008 : Debug: lifetime = 24 Wed Oct 1 11:22:37 2008 : Debug: max_entries = 255 Wed Oct 1 11:22:37 2008 : Debug: } Wed Oct 1 11:22:37 2008 : Debug: } Wed Oct 1 11:22:37 2008 : Debug: Module: Linked to sub-module rlm_eap_ttls Wed Oct 1 11:22:37 2008 : Debug: Module: Instantiating eap-ttls Wed Oct 1 11:22:37 2008 : Debug: ttls { Wed Oct 1 11:22:37 2008 : Debug: default_eap_type = "md5" Wed Oct 1 11:22:37 2008 : Debug: copy_request_to_tunnel = no Wed Oct 1 11:22:37 2008 : Debug: use_tunneled_reply = no Wed Oct 1 11:22:37 2008 : Debug: virtual_server = "inner-tunnel" Wed Oct 1 11:22:37 2008 : Debug: } Wed Oct 1 11:22:37 2008 : Debug: Module: Linked to sub-module rlm_eap_peap Wed Oct 1 11:22:37 2008 : Debug: Module: Instantiating eap-peap Wed Oct 1 11:22:37 2008 : Debug: peap { Wed Oct 1 11:22:37 2008 : Debug: default_eap_type = "mschapv2" Wed Oct 1 11:22:37 2008 : Debug: copy_request_to_tunnel = no Wed Oct 1 11:22:37 2008 : Debug: use_tunneled_reply = no Wed Oct 1 11:22:37 2008 : Debug: proxy_tunneled_request_as_eap = yes Wed Oct 1 11:22:37 2008 : Debug: virtual_server = "inner-tunnel" Wed Oct 1 11:22:37 2008 : Debug: } Wed Oct 1 11:22:37 2008 : Debug: Module: Linked to sub-module rlm_eap_mschapv2 Wed Oct 1 11:22:37 2008 : Debug: Module: Instantiating eap-mschapv2 Wed Oct 1 11:22:37 2008 : Debug: mschapv2 { Wed Oct 1 11:22:37 2008 : Debug: with_ntdomain_hack = no Wed Oct 1 11:22:37 2008 : Debug: } Wed Oct 1 11:22:37 2008 : Debug: Module: Checking authorize {...} for more modules to load Wed Oct 1 11:22:37 2008 : Debug: (Loaded rlm_realm, checking if it's valid) Wed Oct 1 11:22:37 2008 : Debug: Module: Linked to module rlm_realm Wed Oct 1 11:22:37 2008 : Debug: Module: Instantiating suffix Wed Oct 1 11:22:37 2008 : Debug: realm suffix { Wed Oct 1 11:22:37 2008 : Debug: format = "suffix" Wed Oct 1 11:22:37 2008 : Debug: delimiter = "@" Wed Oct 1 11:22:37 2008 : Debug: ignore_default = no Wed Oct 1 11:22:37 2008 : Debug: ignore_null = no Wed Oct 1 11:22:37 2008 : Debug: } Wed Oct 1 11:22:37 2008 : Debug: (Loaded rlm_files, checking if it's valid) Wed Oct 1 11:22:37 2008 : Debug: Module: Linked to module rlm_files Wed Oct 1 11:22:37 2008 : Debug: Module: Instantiating files Wed Oct 1 11:22:37 2008 : Debug: files { Wed Oct 1 11:22:37 2008 : Debug: usersfile = "/home/radius2.11/etc/raddb/users" Wed Oct 1 11:22:37 2008 : Debug: acctusersfile = "/home/radius2.11/etc/raddb/acct_users" Wed Oct 1 11:22:37 2008 : Debug: preproxy_usersfile = "/home/radius2.11/etc/raddb/preproxy_users" Wed Oct 1 11:22:37 2008 : Debug: compat = "no" Wed Oct 1 11:22:37 2008 : Debug: } Wed Oct 1 11:22:37 2008 : Debug: Module: Checking session {...} for more modules to load Wed Oct 1 11:22:37 2008 : Debug: (Loaded rlm_radutmp, checking if it's valid) Wed Oct 1 11:22:37 2008 : Debug: Module: Linked to module rlm_radutmp Wed Oct 1 11:22:37 2008 : Debug: Module: Instantiating radutmp Wed Oct 1 11:22:37 2008 : Debug: radutmp { Wed Oct 1 11:22:37 2008 : Debug: filename = "/home/radius2.11/var/log/radius/radutmp" Wed Oct 1 11:22:37 2008 : Debug: username = "%{User-Name}" Wed Oct 1 11:22:37 2008 : Debug: case_sensitive = yes Wed Oct 1 11:22:37 2008 : Debug: check_with_nas = yes Wed Oct 1 11:22:37 2008 : Debug: perm = 384 Wed Oct 1 11:22:37 2008 : Debug: callerid = yes Wed Oct 1 11:22:37 2008 : Debug: } Wed Oct 1 11:22:37 2008 : Debug: Module: Checking post-proxy {...} for more modules to load Wed Oct 1 11:22:37 2008 : Debug: Module: Checking post-auth {...} for more modules to load Wed Oct 1 11:22:37 2008 : Debug: (Loaded rlm_attr_filter, checking if it's valid) Wed Oct 1 11:22:37 2008 : Debug: Module: Linked to module rlm_attr_filter Wed Oct 1 11:22:37 2008 : Debug: Module: Instantiating attr_filter.access_reject Wed Oct 1 11:22:37 2008 : Debug: attr_filter attr_filter.access_reject { Wed Oct 1 11:22:37 2008 : Debug: attrsfile = "/home/radius2.11/etc/raddb/attrs.access_reject" Wed Oct 1 11:22:37 2008 : Debug: key = "%{User-Name}" Wed Oct 1 11:22:37 2008 : Debug: } Wed Oct 1 11:22:37 2008 : Debug: } Wed Oct 1 11:22:37 2008 : Debug: } Wed Oct 1 11:22:37 2008 : Debug: modules { Wed Oct 1 11:22:37 2008 : Debug: Module: Checking authenticate {...} for more modules to load Wed Oct 1 11:22:37 2008 : Debug: Module: Checking authorize {...} for more modules to load Wed Oct 1 11:22:37 2008 : Debug: (Loaded rlm_preprocess, checking if it's valid) Wed Oct 1 11:22:37 2008 : Debug: Module: Linked to module rlm_preprocess Wed Oct 1 11:22:37 2008 : Debug: Module: Instantiating preprocess Wed Oct 1 11:22:37 2008 : Debug: preprocess { Wed Oct 1 11:22:37 2008 : Debug: huntgroups = "/home/radius2.11/etc/raddb/huntgroups" Wed Oct 1 11:22:37 2008 : Debug: hints = "/home/radius2.11/etc/raddb/hints" Wed Oct 1 11:22:37 2008 : Debug: with_ascend_hack = no Wed Oct 1 11:22:37 2008 : Debug: ascend_channels_per_line = 23 Wed Oct 1 11:22:37 2008 : Debug: with_ntdomain_hack = no Wed Oct 1 11:22:37 2008 : Debug: with_specialix_jetstream_hack = no Wed Oct 1 11:22:37 2008 : Debug: with_cisco_vsa_hack = no Wed Oct 1 11:22:37 2008 : Debug: with_alvarion_vsa_hack = no Wed Oct 1 11:22:37 2008 : Debug: } Wed Oct 1 11:22:37 2008 : Debug: Module: Checking preacct {...} for more modules to load Wed Oct 1 11:22:37 2008 : Debug: (Loaded rlm_acct_unique, checking if it's valid) Wed Oct 1 11:22:37 2008 : Debug: Module: Linked to module rlm_acct_unique Wed Oct 1 11:22:37 2008 : Debug: Module: Instantiating acct_unique Wed Oct 1 11:22:37 2008 : Debug: acct_unique { Wed Oct 1 11:22:37 2008 : Debug: key = "User-Name, Acct-Session-Id, NAS-IP-Address, Client-IP-Address, NAS-Port" Wed Oct 1 11:22:37 2008 : Debug: } Wed Oct 1 11:22:37 2008 : Debug: Module: Checking accounting {...} for more modules to load Wed Oct 1 11:22:37 2008 : Debug: (Loaded rlm_detail, checking if it's valid) Wed Oct 1 11:22:37 2008 : Debug: Module: Linked to module rlm_detail Wed Oct 1 11:22:37 2008 : Debug: Module: Instantiating detail Wed Oct 1 11:22:37 2008 : Debug: detail { Wed Oct 1 11:22:37 2008 : Debug: detailfile = "/home/radius2.11/var/log/radius/radacct/%{Client-IP-Address}/detail-%Y%m%d" Wed Oct 1 11:22:37 2008 : Debug: header = "%t" Wed Oct 1 11:22:37 2008 : Debug: detailperm = 384 Wed Oct 1 11:22:37 2008 : Debug: dirperm = 493 Wed Oct 1 11:22:37 2008 : Debug: locking = no Wed Oct 1 11:22:37 2008 : Debug: log_packet_header = no Wed Oct 1 11:22:37 2008 : Debug: } Wed Oct 1 11:22:37 2008 : Debug: Module: Instantiating attr_filter.accounting_response Wed Oct 1 11:22:37 2008 : Debug: attr_filter attr_filter.accounting_response { Wed Oct 1 11:22:37 2008 : Debug: attrsfile = "/home/radius2.11/etc/raddb/attrs.accounting_response" Wed Oct 1 11:22:37 2008 : Debug: key = "%{User-Name}" Wed Oct 1 11:22:37 2008 : Debug: } Wed Oct 1 11:22:37 2008 : Debug: Module: Checking session {...} for more modules to load Wed Oct 1 11:22:37 2008 : Debug: Module: Checking post-proxy {...} for more modules to load Wed Oct 1 11:22:37 2008 : Debug: Module: Checking post-auth {...} for more modules to load Wed Oct 1 11:22:37 2008 : Debug: } Wed Oct 1 11:22:37 2008 : Debug: radiusd: #### Opening IP addresses and Ports #### Wed Oct 1 11:22:37 2008 : Debug: listen { Wed Oct 1 11:22:37 2008 : Debug: type = "auth" Wed Oct 1 11:22:37 2008 : Debug: ipaddr = * Wed Oct 1 11:22:37 2008 : Debug: port = 0 Wed Oct 1 11:22:37 2008 : Debug: } Wed Oct 1 11:22:37 2008 : Debug: listen { Wed Oct 1 11:22:37 2008 : Debug: type = "acct" Wed Oct 1 11:22:37 2008 : Debug: ipaddr = * Wed Oct 1 11:22:37 2008 : Debug: port = 0 Wed Oct 1 11:22:37 2008 : Debug: } Wed Oct 1 11:22:37 2008 : Debug: Listening on authentication address * port 1812 Wed Oct 1 11:22:37 2008 : Debug: Listening on accounting address * port 1813 Wed Oct 1 11:22:37 2008 : Debug: Listening on proxy address * port 1814 Wed Oct 1 11:22:37 2008 : Debug: Ready to process requests. rad_recv: Access-Request packet from host 10.241.21.202 port 4870, id=80, length=41 User-Name = "a" User-Password = "a" Wed Oct 1 11:22:43 2008 : Info: +- entering group authorize {...} Wed Oct 1 11:22:43 2008 : Info: ++[preprocess] returns ok Wed Oct 1 11:22:43 2008 : Info: ++[chap] returns noop Wed Oct 1 11:22:43 2008 : Info: ++[mschap] returns noop Wed Oct 1 11:22:43 2008 : Info: [suffix] No '@' in User-Name = "a", looking up realm NULL Wed Oct 1 11:22:43 2008 : Info: [suffix] No such realm "NULL" Wed Oct 1 11:22:43 2008 : Info: ++[suffix] returns noop Wed Oct 1 11:22:43 2008 : Info: [eap] No EAP-Message, not doing EAP Wed Oct 1 11:22:43 2008 : Info: ++[eap] returns noop Wed Oct 1 11:22:43 2008 : Info: ++[unix] returns notfound Wed Oct 1 11:22:43 2008 : Info: [files] users: Matched entry a at line 1 Wed Oct 1 11:22:43 2008 : Info: ++[files] returns ok Wed Oct 1 11:22:43 2008 : Info: [expiration] Checking Expiration time: '10 Jan 2009' Wed Oct 1 11:22:43 2008 : Info: [expiration] Account has expired Wed Oct 1 11:22:43 2008 : Info: [expiration] expand: Password Has Expired -> Password Has Expired Wed Oct 1 11:22:43 2008 : Info: ++[expiration] returns userlock Wed Oct 1 11:22:43 2008 : Info: Using Post-Auth-Type Reject Wed Oct 1 11:22:43 2008 : Info: +- entering group REJECT {...} Wed Oct 1 11:22:43 2008 : Info: [attr_filter.access_reject] expand: %{User-Name} -> a Wed Oct 1 11:22:43 2008 : Debug: attr_filter: Matched entry DEFAULT at line 11 Wed Oct 1 11:22:43 2008 : Info: ++[attr_filter.access_reject] returns updated Wed Oct 1 11:22:43 2008 : Info: Delaying reject of request 0 for 1 seconds Wed Oct 1 11:22:43 2008 : Debug: Going to the next request Wed Oct 1 11:22:43 2008 : Debug: Waking up in 0.9 seconds. Wed Oct 1 11:22:44 2008 : Info: Sending delayed reject for request 0 Sending Access-Reject of id 80 to 10.241.21.202 port 4870 Reply-Message += "Password Has Expired\r\n" Wed Oct 1 11:22:44 2008 : Debug: Waking up in 4.9 seconds. Thanks, Flamur