eap-ttls-gtc-pap
Seike neg
seike at outlook.com
Fri Oct 30 17:21:38 CET 2015
Here is my debug thanks in advance
Fri Oct 30 12:01:09 2015 : Info: FreeRADIUS Version 2.1.1, for host x86_64-suse-linux-gnu, built on Feb 25 2013 at 21:56:56
Fri Oct 30 12:01:09 2015 : Info: Copyright (C) 1999-2008 The FreeRADIUS server project and contributors.
Fri Oct 30 12:01:09 2015 : Info: There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A
Fri Oct 30 12:01:09 2015 : Info: PARTICULAR PURPOSE.
Fri Oct 30 12:01:09 2015 : Info: You may redistribute copies of FreeRADIUS under the terms of the
Fri Oct 30 12:01:09 2015 : Info: GNU General Public License v2.
Fri Oct 30 12:01:09 2015 : Info: Starting - reading configuration files ...
Fri Oct 30 12:01:09 2015 : Debug: including configuration file /etc/raddb/radiusd.conf
Fri Oct 30 12:01:09 2015 : Debug: including configuration file /etc/raddb/proxy.conf
Fri Oct 30 12:01:09 2015 : Debug: including configuration file /etc/raddb/clients.conf
Fri Oct 30 12:01:09 2015 : Debug: including files in directory /etc/raddb/modules/
Fri Oct 30 12:01:09 2015 : Debug: including configuration file /etc/raddb/modules/attr_filter
Fri Oct 30 12:01:09 2015 : Debug: including configuration file /etc/raddb/modules/attr_rewrite
Fri Oct 30 12:01:09 2015 : Debug: including configuration file /etc/raddb/modules/mac2vlan
Fri Oct 30 12:01:09 2015 : Debug: including configuration file /etc/raddb/modules/mschap
Fri Oct 30 12:01:09 2015 : Debug: including configuration file /etc/raddb/modules/exec
Fri Oct 30 12:01:09 2015 : Debug: including configuration file /etc/raddb/modules/etc_group
Fri Oct 30 12:01:09 2015 : Debug: including configuration file /etc/raddb/modules/checkval
Fri Oct 30 12:01:09 2015 : Debug: including configuration file /etc/raddb/modules/krb5
Fri Oct 30 12:01:09 2015 : Debug: including configuration file /etc/raddb/modules/detail.example.com
Fri Oct 30 12:01:09 2015 : Debug: including configuration file /etc/raddb/modules/inner-eap
Fri Oct 30 12:01:09 2015 : Debug: including configuration file /etc/raddb/modules/ldap
Fri Oct 30 12:01:09 2015 : Debug: including configuration file /etc/raddb/modules/expiration
Fri Oct 30 12:01:09 2015 : Debug: including configuration file /etc/raddb/modules/logintime
Fri Oct 30 12:01:09 2015 : Debug: including configuration file /etc/raddb/modules/realm
Fri Oct 30 12:01:09 2015 : Debug: including configuration file /etc/raddb/modules/passwd
Fri Oct 30 12:01:09 2015 : Debug: including configuration file /etc/raddb/modules/always
Fri Oct 30 12:01:09 2015 : Debug: including configuration file /etc/raddb/modules/unix
Fri Oct 30 12:01:09 2015 : Debug: including configuration file /etc/raddb/modules/sradutmp
Fri Oct 30 12:01:09 2015 : Debug: including configuration file /etc/raddb/modules/expr
Fri Oct 30 12:01:09 2015 : Debug: including configuration file /etc/raddb/modules/detail
Fri Oct 30 12:01:09 2015 : Debug: including configuration file /etc/raddb/modules/mac2ip
Fri Oct 30 12:01:09 2015 : Debug: including configuration file /etc/raddb/modules/digest
Fri Oct 30 12:01:09 2015 : Debug: including configuration file /etc/raddb/modules/ippool
Fri Oct 30 12:01:09 2015 : Debug: including configuration file /etc/raddb/modules/linelog
Fri Oct 30 12:01:09 2015 : Debug: including configuration file /etc/raddb/modules/sql_log
Fri Oct 30 12:01:09 2015 : Debug: including configuration file /etc/raddb/modules/policy
Fri Oct 30 12:01:09 2015 : Debug: including configuration file /etc/raddb/modules/chap
Fri Oct 30 12:01:09 2015 : Debug: including configuration file /etc/raddb/modules/pap
Fri Oct 30 12:01:09 2015 : Debug: including configuration file /etc/raddb/modules/pam
Fri Oct 30 12:01:09 2015 : Debug: including configuration file /etc/raddb/modules/preprocess
Fri Oct 30 12:01:09 2015 : Debug: including configuration file /etc/raddb/modules/smbpasswd
Fri Oct 30 12:01:09 2015 : Debug: including configuration file /etc/raddb/modules/wimax
Fri Oct 30 12:01:09 2015 : Debug: including configuration file /etc/raddb/modules/detail.log
Fri Oct 30 12:01:09 2015 : Debug: including configuration file /etc/raddb/modules/acct_unique
Fri Oct 30 12:01:09 2015 : Debug: including configuration file /etc/raddb/modules/radutmp
Fri Oct 30 12:01:09 2015 : Debug: including configuration file /etc/raddb/modules/counter
Fri Oct 30 12:01:09 2015 : Debug: including configuration file /etc/raddb/modules/files
Fri Oct 30 12:01:09 2015 : Debug: including configuration file /etc/raddb/modules/echo
Fri Oct 30 12:01:09 2015 : Debug: including configuration file /etc/raddb/eap.conf
Fri Oct 30 12:01:09 2015 : Debug: including configuration file /etc/raddb/sql.conf
Fri Oct 30 12:01:09 2015 : Debug: including configuration file /etc/raddb/sql/mysql/dialup.conf
Fri Oct 30 12:01:09 2015 : Debug: including configuration file /etc/raddb/sql/mysql/counter.conf
Fri Oct 30 12:01:09 2015 : Debug: including configuration file /etc/raddb/policy.conf
Fri Oct 30 12:01:09 2015 : Debug: including files in directory /etc/raddb/sites-enabled/
Fri Oct 30 12:01:09 2015 : Debug: including configuration file /etc/raddb/sites-enabled/inner-tunnel
Fri Oct 30 12:01:09 2015 : Debug: including configuration file /etc/raddb/sites-enabled/default
Fri Oct 30 12:01:09 2015 : Debug: including configuration file /etc/raddb/sites-enabled/inner-tunnel-bak
Fri Oct 30 12:01:09 2015 : Debug: group = radiusd
Fri Oct 30 12:01:09 2015 : Debug: user = radiusd
Fri Oct 30 12:01:09 2015 : Debug: including dictionary file /etc/raddb/dictionary
Fri Oct 30 12:01:09 2015 : Debug: main {
Fri Oct 30 12:01:09 2015 : Debug: prefix = "/usr"
Fri Oct 30 12:01:09 2015 : Debug: localstatedir = "/var"
Fri Oct 30 12:01:09 2015 : Debug: logdir = "/var/log/radius"
Fri Oct 30 12:01:09 2015 : Debug: libdir = "/usr/lib64/freeradius"
Fri Oct 30 12:01:09 2015 : Debug: radacctdir = "/var/log/radius/radacct"
Fri Oct 30 12:01:09 2015 : Debug: hostname_lookups = no
Fri Oct 30 12:01:09 2015 : Debug: max_request_time = 30
Fri Oct 30 12:01:09 2015 : Debug: cleanup_delay = 5
Fri Oct 30 12:01:09 2015 : Debug: max_requests = 1024
Fri Oct 30 12:01:09 2015 : Debug: allow_core_dumps = no
Fri Oct 30 12:01:09 2015 : Debug: pidfile = "/var/run/radiusd/radiusd.pid"
Fri Oct 30 12:01:09 2015 : Debug: checkrad = "/usr/sbin/checkrad"
Fri Oct 30 12:01:09 2015 : Debug: debug_level = 0
Fri Oct 30 12:01:09 2015 : Debug: proxy_requests = yes
Fri Oct 30 12:01:09 2015 : Debug: log {
Fri Oct 30 12:01:09 2015 : Debug: stripped_names = no
Fri Oct 30 12:01:09 2015 : Debug: auth = no
Fri Oct 30 12:01:09 2015 : Debug: auth_badpass = no
Fri Oct 30 12:01:09 2015 : Debug: auth_goodpass = no
Fri Oct 30 12:01:09 2015 : Debug: }
Fri Oct 30 12:01:09 2015 : Debug: security {
Fri Oct 30 12:01:09 2015 : Debug: max_attributes = 200
Fri Oct 30 12:01:09 2015 : Debug: reject_delay = 1
Fri Oct 30 12:01:09 2015 : Debug: status_server = yes
Fri Oct 30 12:01:09 2015 : Debug: }
Fri Oct 30 12:01:09 2015 : Debug: }
Fri Oct 30 12:01:09 2015 : Debug: client localhost {
Fri Oct 30 12:01:09 2015 : Debug: ipaddr = 127.0.0.1
Fri Oct 30 12:01:09 2015 : Debug: require_message_authenticator = no
Fri Oct 30 12:01:09 2015 : Debug: secret = "testing123"
Fri Oct 30 12:01:09 2015 : Debug: nastype = "other"
Fri Oct 30 12:01:09 2015 : Debug: }
Fri Oct 30 12:01:09 2015 : Debug: client x.x.x.11 {
Fri Oct 30 12:01:09 2015 : Debug: require_message_authenticator = no
Fri Oct 30 12:01:09 2015 : Debug: secret = "testing123"
Fri Oct 30 12:01:09 2015 : Debug: shortname = "AP1"
Fri Oct 30 12:01:09 2015 : Debug: }
Fri Oct 30 12:01:09 2015 : Debug: client x.x.x.12 {
Fri Oct 30 12:01:09 2015 : Debug: require_message_authenticator = no
Fri Oct 30 12:01:09 2015 : Debug: secret = "testing123"
Fri Oct 30 12:01:09 2015 : Debug: shortname = "AP2"
Fri Oct 30 12:01:09 2015 : Debug: }
Fri Oct 30 12:01:09 2015 : Debug: client x.x.y.0/24 {
Fri Oct 30 12:01:09 2015 : Debug: require_message_authenticator = no
Fri Oct 30 12:01:09 2015 : Debug: secret = "testing123"
Fri Oct 30 12:01:09 2015 : Debug: shortname = "private-network-1"
Fri Oct 30 12:01:09 2015 : Debug: }
Fri Oct 30 12:01:09 2015 : Debug: client x.x.x.0/24 {
Fri Oct 30 12:01:09 2015 : Debug: require_message_authenticator = no
Fri Oct 30 12:01:09 2015 : Debug: secret = "testing123"
Fri Oct 30 12:01:09 2015 : Debug: shortname = "private-network-2"
Fri Oct 30 12:01:09 2015 : Debug: }
Fri Oct 30 12:01:09 2015 : Debug: radiusd: #### Loading Realms and Home Servers ####
Fri Oct 30 12:01:09 2015 : Debug: proxy server {
Fri Oct 30 12:01:09 2015 : Debug: retry_delay = 5
Fri Oct 30 12:01:09 2015 : Debug: retry_count = 3
Fri Oct 30 12:01:09 2015 : Debug: default_fallback = no
Fri Oct 30 12:01:09 2015 : Debug: dead_time = 120
Fri Oct 30 12:01:09 2015 : Debug: wake_all_if_all_dead = no
Fri Oct 30 12:01:09 2015 : Debug: }
Fri Oct 30 12:01:09 2015 : Debug: home_server localhost {
Fri Oct 30 12:01:09 2015 : Debug: ipaddr = 127.0.0.1
Fri Oct 30 12:01:09 2015 : Debug: port = 1812
Fri Oct 30 12:01:09 2015 : Debug: type = "auth"
Fri Oct 30 12:01:09 2015 : Debug: secret = "testing123"
Fri Oct 30 12:01:09 2015 : Debug: response_window = 20
Fri Oct 30 12:01:09 2015 : Debug: max_outstanding = 65536
Fri Oct 30 12:01:09 2015 : Debug: zombie_period = 40
Fri Oct 30 12:01:09 2015 : Debug: status_check = "status-server"
Fri Oct 30 12:01:09 2015 : Debug: ping_interval = 30
Fri Oct 30 12:01:09 2015 : Debug: check_interval = 30
Fri Oct 30 12:01:09 2015 : Debug: num_answers_to_alive = 3
Fri Oct 30 12:01:09 2015 : Debug: num_pings_to_alive = 3
Fri Oct 30 12:01:09 2015 : Debug: revive_interval = 120
Fri Oct 30 12:01:09 2015 : Debug: status_check_timeout = 4
Fri Oct 30 12:01:09 2015 : Debug: }
Fri Oct 30 12:01:09 2015 : Debug: home_server_pool my_auth_failover {
Fri Oct 30 12:01:09 2015 : Debug: type = fail-over
Fri Oct 30 12:01:09 2015 : Debug: home_server = localhost
Fri Oct 30 12:01:09 2015 : Debug: }
Fri Oct 30 12:01:09 2015 : Debug: realm example.com {
Fri Oct 30 12:01:09 2015 : Debug: auth_pool = my_auth_failover
Fri Oct 30 12:01:09 2015 : Debug: }
Fri Oct 30 12:01:09 2015 : Debug: realm LOCAL {
Fri Oct 30 12:01:09 2015 : Debug: }
Fri Oct 30 12:01:09 2015 : Debug: radiusd: #### Instantiating modules ####
Fri Oct 30 12:01:09 2015 : Debug: instantiate {
Fri Oct 30 12:01:09 2015 : Debug: (Loaded rlm_exec, checking if it's valid)
Fri Oct 30 12:01:09 2015 : Debug: Module: Linked to module rlm_exec
Fri Oct 30 12:01:09 2015 : Debug: Module: Instantiating exec
Fri Oct 30 12:01:09 2015 : Debug: exec {
Fri Oct 30 12:01:09 2015 : Debug: wait = no
Fri Oct 30 12:01:09 2015 : Debug: input_pairs = "request"
Fri Oct 30 12:01:09 2015 : Debug: shell_escape = yes
Fri Oct 30 12:01:09 2015 : Debug: }
Fri Oct 30 12:01:09 2015 : Debug: (Loaded rlm_expr, checking if it's valid)
Fri Oct 30 12:01:09 2015 : Debug: Module: Linked to module rlm_expr
Fri Oct 30 12:01:09 2015 : Debug: Module: Instantiating expr
Fri Oct 30 12:01:09 2015 : Debug: (Loaded rlm_expiration, checking if it's valid)
Fri Oct 30 12:01:09 2015 : Debug: Module: Linked to module rlm_expiration
Fri Oct 30 12:01:09 2015 : Debug: Module: Instantiating expiration
Fri Oct 30 12:01:09 2015 : Debug: expiration {
Fri Oct 30 12:01:09 2015 : Debug: reply-message = "Password Has Expired "
Fri Oct 30 12:01:09 2015 : Debug: }
Fri Oct 30 12:01:09 2015 : Debug: (Loaded rlm_logintime, checking if it's valid)
Fri Oct 30 12:01:09 2015 : Debug: Module: Linked to module rlm_logintime
Fri Oct 30 12:01:09 2015 : Debug: Module: Instantiating logintime
Fri Oct 30 12:01:09 2015 : Debug: logintime {
Fri Oct 30 12:01:09 2015 : Debug: reply-message = "You are calling outside your allowed timespan "
Fri Oct 30 12:01:09 2015 : Debug: minimum-timeout = 60
Fri Oct 30 12:01:09 2015 : Debug: }
Fri Oct 30 12:01:09 2015 : Debug: }
Fri Oct 30 12:01:09 2015 : Debug: radiusd: #### Loading Virtual Servers ####
Fri Oct 30 12:01:09 2015 : Debug: server inner-tunnel {
Fri Oct 30 12:01:09 2015 : Debug: modules {
Fri Oct 30 12:01:09 2015 : Debug: Module: Checking authenticate {...} for more modules to load
Fri Oct 30 12:01:09 2015 : Debug: (Loaded rlm_pap, checking if it's valid)
Fri Oct 30 12:01:09 2015 : Debug: Module: Linked to module rlm_pap
Fri Oct 30 12:01:09 2015 : Debug: Module: Instantiating pap
Fri Oct 30 12:01:09 2015 : Debug: pap {
Fri Oct 30 12:01:09 2015 : Debug: encryption_scheme = "auto"
Fri Oct 30 12:01:09 2015 : Debug: auto_header = yes
Fri Oct 30 12:01:09 2015 : Debug: }
Fri Oct 30 12:01:09 2015 : Debug: (Loaded rlm_eap, checking if it's valid)
Fri Oct 30 12:01:09 2015 : Debug: Module: Linked to module rlm_eap
Fri Oct 30 12:01:09 2015 : Debug: Module: Instantiating eap
Fri Oct 30 12:01:09 2015 : Debug: eap {
Fri Oct 30 12:01:09 2015 : Debug: default_eap_type = "ttls"
Fri Oct 30 12:01:09 2015 : Debug: timer_expire = 60
Fri Oct 30 12:01:09 2015 : Debug: ignore_unknown_eap_types = no
Fri Oct 30 12:01:09 2015 : Debug: cisco_accounting_username_bug = no
Fri Oct 30 12:01:09 2015 : Debug: max_sessions = 2048
Fri Oct 30 12:01:09 2015 : Debug: }
Fri Oct 30 12:01:09 2015 : Debug: Module: Linked to sub-module rlm_eap_md5
Fri Oct 30 12:01:09 2015 : Debug: Module: Instantiating eap-md5
Fri Oct 30 12:01:09 2015 : Debug: Module: Linked to sub-module rlm_eap_gtc
Fri Oct 30 12:01:09 2015 : Debug: Module: Instantiating eap-gtc
Fri Oct 30 12:01:09 2015 : Debug: gtc {
Fri Oct 30 12:01:09 2015 : Debug: challenge = "Password: "
Fri Oct 30 12:01:09 2015 : Debug: auth_type = "PAP"
Fri Oct 30 12:01:09 2015 : Debug: }
Fri Oct 30 12:01:09 2015 : Debug: Module: Linked to sub-module rlm_eap_tls
Fri Oct 30 12:01:09 2015 : Debug: Module: Instantiating eap-tls
Fri Oct 30 12:01:09 2015 : Debug: tls {
Fri Oct 30 12:01:09 2015 : Debug: rsa_key_exchange = no
Fri Oct 30 12:01:09 2015 : Debug: dh_key_exchange = yes
Fri Oct 30 12:01:09 2015 : Debug: rsa_key_length = 512
Fri Oct 30 12:01:09 2015 : Debug: dh_key_length = 512
Fri Oct 30 12:01:09 2015 : Debug: verify_depth = 0
Fri Oct 30 12:01:09 2015 : Debug: pem_file_type = yes
Fri Oct 30 12:01:09 2015 : Debug: private_key_file = "/etc/raddb/certs/server.pem"
Fri Oct 30 12:01:09 2015 : Debug: certificate_file = "/etc/raddb/certs/server.pem"
Fri Oct 30 12:01:09 2015 : Debug: CA_file = "/etc/raddb/certs/ca.pem"
Fri Oct 30 12:01:09 2015 : Debug: private_key_password = "whatever"
Fri Oct 30 12:01:09 2015 : Debug: dh_file = "/etc/raddb/certs/dh"
Fri Oct 30 12:01:09 2015 : Debug: random_file = "/etc/raddb/certs/random"
Fri Oct 30 12:01:09 2015 : Debug: fragment_size = 1024
Fri Oct 30 12:01:09 2015 : Debug: include_length = yes
Fri Oct 30 12:01:09 2015 : Debug: check_crl = no
Fri Oct 30 12:01:09 2015 : Debug: cipher_list = "DEFAULT"
Fri Oct 30 12:01:09 2015 : Debug: make_cert_command = "/etc/raddb/certs/bootstrap"
Fri Oct 30 12:01:09 2015 : Debug: cache {
Fri Oct 30 12:01:09 2015 : Debug: enable = no
Fri Oct 30 12:01:09 2015 : Debug: lifetime = 24
Fri Oct 30 12:01:09 2015 : Debug: max_entries = 255
Fri Oct 30 12:01:09 2015 : Debug: }
Fri Oct 30 12:01:09 2015 : Debug: }
Fri Oct 30 12:01:09 2015 : Debug: Module: Linked to sub-module rlm_eap_ttls
Fri Oct 30 12:01:09 2015 : Debug: Module: Instantiating eap-ttls
Fri Oct 30 12:01:09 2015 : Debug: ttls {
Fri Oct 30 12:01:09 2015 : Debug: default_eap_type = "gtc"
Fri Oct 30 12:01:09 2015 : Debug: copy_request_to_tunnel = yes
Fri Oct 30 12:01:09 2015 : Debug: use_tunneled_reply = yes
Fri Oct 30 12:01:09 2015 : Debug: virtual_server = "inner-tunnel"
Fri Oct 30 12:01:09 2015 : Debug: }
Fri Oct 30 12:01:09 2015 : Debug: Module: Linked to sub-module rlm_eap_peap
Fri Oct 30 12:01:09 2015 : Debug: Module: Instantiating eap-peap
Fri Oct 30 12:01:09 2015 : Debug: peap {
Fri Oct 30 12:01:09 2015 : Debug: default_eap_type = "mschapv2"
Fri Oct 30 12:01:09 2015 : Debug: copy_request_to_tunnel = no
Fri Oct 30 12:01:09 2015 : Debug: use_tunneled_reply = no
Fri Oct 30 12:01:09 2015 : Debug: proxy_tunneled_request_as_eap = yes
Fri Oct 30 12:01:09 2015 : Debug: virtual_server = "inner-tunnel"
Fri Oct 30 12:01:09 2015 : Debug: }
Fri Oct 30 12:01:09 2015 : Debug: Module: Linked to sub-module rlm_eap_mschapv2
Fri Oct 30 12:01:09 2015 : Debug: Module: Instantiating eap-mschapv2
Fri Oct 30 12:01:09 2015 : Debug: mschapv2 {
Fri Oct 30 12:01:09 2015 : Debug: with_ntdomain_hack = no
Fri Oct 30 12:01:09 2015 : Debug: }
Fri Oct 30 12:01:09 2015 : Debug: Module: Checking authorize {...} for more modules to load
Fri Oct 30 12:01:09 2015 : Debug: (Loaded rlm_realm, checking if it's valid)
Fri Oct 30 12:01:09 2015 : Debug: Module: Linked to module rlm_realm
Fri Oct 30 12:01:09 2015 : Debug: Module: Instantiating suffix
Fri Oct 30 12:01:09 2015 : Debug: realm suffix {
Fri Oct 30 12:01:09 2015 : Debug: format = "suffix"
Fri Oct 30 12:01:09 2015 : Debug: delimiter = "@"
Fri Oct 30 12:01:09 2015 : Debug: ignore_default = no
Fri Oct 30 12:01:09 2015 : Debug: ignore_null = no
Fri Oct 30 12:01:09 2015 : Debug: }
Fri Oct 30 12:01:09 2015 : Debug: Module: Checking session {...} for more modules to load
Fri Oct 30 12:01:09 2015 : Debug: (Loaded rlm_radutmp, checking if it's valid)
Fri Oct 30 12:01:09 2015 : Debug: Module: Linked to module rlm_radutmp
Fri Oct 30 12:01:09 2015 : Debug: Module: Instantiating radutmp
Fri Oct 30 12:01:09 2015 : Debug: radutmp {
Fri Oct 30 12:01:09 2015 : Debug: filename = "/var/log/radius/radutmp"
Fri Oct 30 12:01:09 2015 : Debug: username = "%{User-Name}"
Fri Oct 30 12:01:09 2015 : Debug: case_sensitive = yes
Fri Oct 30 12:01:09 2015 : Debug: check_with_nas = yes
Fri Oct 30 12:01:09 2015 : Debug: perm = 384
Fri Oct 30 12:01:09 2015 : Debug: callerid = yes
Fri Oct 30 12:01:09 2015 : Debug: }
Fri Oct 30 12:01:09 2015 : Debug: Module: Checking post-proxy {...} for more modules to load
Fri Oct 30 12:01:09 2015 : Debug: Module: Checking post-auth {...} for more modules to load
Fri Oct 30 12:01:09 2015 : Debug: (Loaded rlm_attr_filter, checking if it's valid)
Fri Oct 30 12:01:09 2015 : Debug: Module: Linked to module rlm_attr_filter
Fri Oct 30 12:01:09 2015 : Debug: Module: Instantiating attr_filter.access_reject
Fri Oct 30 12:01:09 2015 : Debug: attr_filter attr_filter.access_reject {
Fri Oct 30 12:01:09 2015 : Debug: attrsfile = "/etc/raddb/attrs.access_reject"
Fri Oct 30 12:01:09 2015 : Debug: key = "%{User-Name}"
Fri Oct 30 12:01:09 2015 : Debug: }
Fri Oct 30 12:01:09 2015 : Debug: }
Fri Oct 30 12:01:09 2015 : Debug: }
Fri Oct 30 12:01:09 2015 : Debug: server inner-tunnel {
Fri Oct 30 12:01:09 2015 : Debug: modules {
Fri Oct 30 12:01:09 2015 : Debug: Module: Checking authenticate {...} for more modules to load
Fri Oct 30 12:01:09 2015 : Debug: (Loaded rlm_chap, checking if it's valid)
Fri Oct 30 12:01:09 2015 : Debug: Module: Linked to module rlm_chap
Fri Oct 30 12:01:09 2015 : Debug: Module: Instantiating chap
Fri Oct 30 12:01:09 2015 : Debug: (Loaded rlm_mschap, checking if it's valid)
Fri Oct 30 12:01:09 2015 : Debug: Module: Linked to module rlm_mschap
Fri Oct 30 12:01:09 2015 : Debug: Module: Instantiating mschap
Fri Oct 30 12:01:09 2015 : Debug: mschap {
Fri Oct 30 12:01:09 2015 : Debug: use_mppe = yes
Fri Oct 30 12:01:09 2015 : Debug: require_encryption = no
Fri Oct 30 12:01:09 2015 : Debug: require_strong = no
Fri Oct 30 12:01:09 2015 : Debug: with_ntdomain_hack = no
Fri Oct 30 12:01:09 2015 : Debug: }
Fri Oct 30 12:01:09 2015 : Debug: (Loaded rlm_ldap, checking if it's valid)
Fri Oct 30 12:01:09 2015 : Debug: Module: Linked to module rlm_ldap
Fri Oct 30 12:01:09 2015 : Debug: Module: Instantiating ldap
Fri Oct 30 12:01:09 2015 : Debug: ldap {
Fri Oct 30 12:01:09 2015 : Debug: server = "x.x.x.x"
Fri Oct 30 12:01:09 2015 : Debug: port = 389
Fri Oct 30 12:01:09 2015 : Debug: password = "xxxxx"
Fri Oct 30 12:01:09 2015 : Debug: identity = "xxxxxx"
Fri Oct 30 12:01:09 2015 : Debug: net_timeout = 1
Fri Oct 30 12:01:09 2015 : Debug: timeout = 10
Fri Oct 30 12:01:09 2015 : Debug: timelimit = 10
Fri Oct 30 12:01:09 2015 : Debug: tls_mode = no
Fri Oct 30 12:01:09 2015 : Debug: start_tls = no
Fri Oct 30 12:01:09 2015 : Debug: tls_require_cert = "allow"
Fri Oct 30 12:01:09 2015 : Debug: tls {
Fri Oct 30 12:01:09 2015 : Debug: start_tls = no
Fri Oct 30 12:01:09 2015 : Debug: require_cert = "allow"
Fri Oct 30 12:01:09 2015 : Debug: }
Fri Oct 30 12:01:09 2015 : Debug: basedn = "xxxx"
Fri Oct 30 12:01:09 2015 : Debug: filter = "(uid=%{Stripped-User-Name:-%{User-Name}})"
Fri Oct 30 12:01:09 2015 : Debug: base_filter = "(objectclass=radiusprofile)"
Fri Oct 30 12:01:09 2015 : Debug: password_attribute = "userPassword"
Fri Oct 30 12:01:09 2015 : Debug: auto_header = no
Fri Oct 30 12:01:09 2015 : Debug: access_attr_used_for_allow = yes
Fri Oct 30 12:01:09 2015 : Debug: groupname_attribute = "cn"
Fri Oct 30 12:01:09 2015 : Debug: groupmembership_filter = "(|(&(objectClass=GroupOfNames)(member=%{Ldap-UserDn}))(&(objectClass=GroupOfUniqueNames)(uniquemember=%{Ldap-UserDn})))"
Fri Oct 30 12:01:09 2015 : Debug: dictionary_mapping = "/etc/raddb/ldap.attrmap"
Fri Oct 30 12:01:09 2015 : Debug: ldap_debug = 0
Fri Oct 30 12:01:09 2015 : Debug: ldap_connections_number = 10
Fri Oct 30 12:01:09 2015 : Debug: compare_check_items = no
Fri Oct 30 12:01:09 2015 : Debug: do_xlat = yes
Fri Oct 30 12:01:09 2015 : Debug: edir_account_policy_check = no
Fri Oct 30 12:01:09 2015 : Debug: set_auth_type = yes
Fri Oct 30 12:01:09 2015 : Debug: }
Fri Oct 30 12:01:09 2015 : Debug: rlm_ldap: Registering ldap_groupcmp for Ldap-Group
Fri Oct 30 12:01:09 2015 : Debug: rlm_ldap: Registering ldap_xlat with xlat_name ldap
Fri Oct 30 12:01:09 2015 : Debug: rlm_ldap: reading ldap<->radius mappings from file /etc/raddb/ldap.attrmap
Fri Oct 30 12:01:09 2015 : Debug: rlm_ldap: LDAP radiusCheckItem mapped to RADIUS $GENERIC$
Fri Oct 30 12:01:09 2015 : Debug: rlm_ldap: LDAP radiusReplyItem mapped to RADIUS $GENERIC$
Fri Oct 30 12:01:09 2015 : Debug: rlm_ldap: LDAP radiusAuthType mapped to RADIUS Auth-Type
Fri Oct 30 12:01:09 2015 : Debug: rlm_ldap: LDAP radiusSimultaneousUse mapped to RADIUS Simultaneous-Use
Fri Oct 30 12:01:09 2015 : Debug: rlm_ldap: LDAP radiusCalledStationId mapped to RADIUS Called-Station-Id
Fri Oct 30 12:01:09 2015 : Debug: rlm_ldap: LDAP radiusCallingStationId mapped to RADIUS Calling-Station-Id
Fri Oct 30 12:01:09 2015 : Debug: rlm_ldap: LDAP lmPassword mapped to RADIUS LM-Password
Fri Oct 30 12:01:09 2015 : Debug: rlm_ldap: LDAP ntPassword mapped to RADIUS NT-Password
Fri Oct 30 12:01:09 2015 : Debug: rlm_ldap: LDAP sambaLmPassword mapped to RADIUS LM-Password
Fri Oct 30 12:01:09 2015 : Debug: rlm_ldap: LDAP sambaNtPassword mapped to RADIUS NT-Password
Fri Oct 30 12:01:09 2015 : Debug: rlm_ldap: LDAP dBCSPwd mapped to RADIUS LM-Password
Fri Oct 30 12:01:09 2015 : Debug: rlm_ldap: LDAP userPassword mapped to RADIUS Password-With-Header
Fri Oct 30 12:01:09 2015 : Debug: rlm_ldap: LDAP acctFlags mapped to RADIUS SMB-Account-CTRL-TEXT
Fri Oct 30 12:01:09 2015 : Debug: rlm_ldap: LDAP radiusExpiration mapped to RADIUS Expiration
Fri Oct 30 12:01:09 2015 : Debug: rlm_ldap: LDAP radiusNASIpAddress mapped to RADIUS NAS-IP-Address
Fri Oct 30 12:01:09 2015 : Debug: rlm_ldap: LDAP radiusServiceType mapped to RADIUS Service-Type
Fri Oct 30 12:01:09 2015 : Debug: rlm_ldap: LDAP radiusFramedProtocol mapped to RADIUS Framed-Protocol
Fri Oct 30 12:01:09 2015 : Debug: rlm_ldap: LDAP radiusFramedIPAddress mapped to RADIUS Framed-IP-Address
Fri Oct 30 12:01:09 2015 : Debug: rlm_ldap: LDAP radiusFramedIPNetmask mapped to RADIUS Framed-IP-Netmask
Fri Oct 30 12:01:09 2015 : Debug: rlm_ldap: LDAP radiusFramedRoute mapped to RADIUS Framed-Route
Fri Oct 30 12:01:09 2015 : Debug: rlm_ldap: LDAP radiusFramedRouting mapped to RADIUS Framed-Routing
Fri Oct 30 12:01:09 2015 : Debug: rlm_ldap: LDAP radiusFilterId mapped to RADIUS Filter-Id
Fri Oct 30 12:01:09 2015 : Debug: rlm_ldap: LDAP radiusFramedMTU mapped to RADIUS Framed-MTU
Fri Oct 30 12:01:09 2015 : Debug: rlm_ldap: LDAP radiusFramedCompression mapped to RADIUS Framed-Compression
Fri Oct 30 12:01:09 2015 : Debug: rlm_ldap: LDAP radiusLoginIPHost mapped to RADIUS Login-IP-Host
Fri Oct 30 12:01:09 2015 : Debug: rlm_ldap: LDAP radiusLoginService mapped to RADIUS Login-Service
Fri Oct 30 12:01:09 2015 : Debug: rlm_ldap: LDAP radiusLoginTCPPort mapped to RADIUS Login-TCP-Port
Fri Oct 30 12:01:09 2015 : Debug: rlm_ldap: LDAP radiusCallbackNumber mapped to RADIUS Callback-Number
Fri Oct 30 12:01:09 2015 : Debug: rlm_ldap: LDAP radiusCallbackId mapped to RADIUS Callback-Id
Fri Oct 30 12:01:09 2015 : Debug: rlm_ldap: LDAP radiusFramedIPXNetwork mapped to RADIUS Framed-IPX-Network
Fri Oct 30 12:01:09 2015 : Debug: rlm_ldap: LDAP radiusClass mapped to RADIUS Class
Fri Oct 30 12:01:09 2015 : Debug: rlm_ldap: LDAP radiusSessionTimeout mapped to RADIUS Session-Timeout
Fri Oct 30 12:01:09 2015 : Debug: rlm_ldap: LDAP radiusIdleTimeout mapped to RADIUS Idle-Timeout
Fri Oct 30 12:01:09 2015 : Debug: rlm_ldap: LDAP radiusTerminationAction mapped to RADIUS Termination-Action
Fri Oct 30 12:01:09 2015 : Debug: rlm_ldap: LDAP radiusLoginLATService mapped to RADIUS Login-LAT-Service
Fri Oct 30 12:01:09 2015 : Debug: rlm_ldap: LDAP radiusLoginLATNode mapped to RADIUS Login-LAT-Node
Fri Oct 30 12:01:09 2015 : Debug: rlm_ldap: LDAP radiusLoginLATGroup mapped to RADIUS Login-LAT-Group
Fri Oct 30 12:01:09 2015 : Debug: rlm_ldap: LDAP radiusFramedAppleTalkLink mapped to RADIUS Framed-AppleTalk-Link
Fri Oct 30 12:01:09 2015 : Debug: rlm_ldap: LDAP radiusFramedAppleTalkNetwork mapped to RADIUS Framed-AppleTalk-Network
Fri Oct 30 12:01:09 2015 : Debug: rlm_ldap: LDAP radiusFramedAppleTalkZone mapped to RADIUS Framed-AppleTalk-Zone
Fri Oct 30 12:01:09 2015 : Debug: rlm_ldap: LDAP radiusPortLimit mapped to RADIUS Port-Limit
Fri Oct 30 12:01:09 2015 : Debug: rlm_ldap: LDAP radiusLoginLATPort mapped to RADIUS Login-LAT-Port
Fri Oct 30 12:01:09 2015 : Debug: rlm_ldap: LDAP radiusReplyMessage mapped to RADIUS Reply-Message
Fri Oct 30 12:01:09 2015 : Debug: rlm_ldap: LDAP radiusTunnelType mapped to RADIUS Tunnel-Type
Fri Oct 30 12:01:09 2015 : Debug: rlm_ldap: LDAP radiusTunnelMediumType mapped to RADIUS Tunnel-Medium-Type
Fri Oct 30 12:01:09 2015 : Debug: rlm_ldap: LDAP radiusTunnelPrivateGroupId mapped to RADIUS Tunnel-Private-Group-Id
Fri Oct 30 12:01:09 2015 : Debug: conns: 0x7f04fd6cdfa0
Fri Oct 30 12:01:09 2015 : Debug: Module: Checking authorize {...} for more modules to load
Fri Oct 30 12:01:09 2015 : Debug: (Loaded rlm_files, checking if it's valid)
Fri Oct 30 12:01:09 2015 : Debug: Module: Linked to module rlm_files
Fri Oct 30 12:01:09 2015 : Debug: Module: Instantiating files
Fri Oct 30 12:01:09 2015 : Debug: files {
Fri Oct 30 12:01:09 2015 : Debug: usersfile = "/etc/raddb/users"
Fri Oct 30 12:01:09 2015 : Debug: acctusersfile = "/etc/raddb/acct_users"
Fri Oct 30 12:01:09 2015 : Debug: preproxy_usersfile = "/etc/raddb/preproxy_users"
Fri Oct 30 12:01:09 2015 : Debug: compat = "no"
Fri Oct 30 12:01:09 2015 : Debug: }
Fri Oct 30 12:01:09 2015 : Debug: Module: Checking session {...} for more modules to load
Fri Oct 30 12:01:09 2015 : Debug: Module: Checking post-proxy {...} for more modules to load
Fri Oct 30 12:01:09 2015 : Debug: Module: Checking post-auth {...} for more modules to load
Fri Oct 30 12:01:09 2015 : Debug: }
Fri Oct 30 12:01:09 2015 : Debug: }
Fri Oct 30 12:01:09 2015 : Debug: modules {
Fri Oct 30 12:01:09 2015 : Debug: Module: Checking authenticate {...} for more modules to load
Fri Oct 30 12:01:09 2015 : Debug: Module: Checking authorize {...} for more modules to load
Fri Oct 30 12:01:09 2015 : Debug: (Loaded rlm_preprocess, checking if it's valid)
Fri Oct 30 12:01:09 2015 : Debug: Module: Linked to module rlm_preprocess
Fri Oct 30 12:01:09 2015 : Debug: Module: Instantiating preprocess
Fri Oct 30 12:01:09 2015 : Debug: preprocess {
Fri Oct 30 12:01:09 2015 : Debug: huntgroups = "/etc/raddb/huntgroups"
Fri Oct 30 12:01:09 2015 : Debug: hints = "/etc/raddb/hints"
Fri Oct 30 12:01:09 2015 : Debug: with_ascend_hack = no
Fri Oct 30 12:01:09 2015 : Debug: ascend_channels_per_line = 23
Fri Oct 30 12:01:09 2015 : Debug: with_ntdomain_hack = no
Fri Oct 30 12:01:09 2015 : Debug: with_specialix_jetstream_hack = no
Fri Oct 30 12:01:09 2015 : Debug: with_cisco_vsa_hack = no
Fri Oct 30 12:01:09 2015 : Debug: with_alvarion_vsa_hack = no
Fri Oct 30 12:01:09 2015 : Debug: }
Fri Oct 30 12:01:09 2015 : Debug: Module: Checking preacct {...} for more modules to load
Fri Oct 30 12:01:09 2015 : Debug: (Loaded rlm_acct_unique, checking if it's valid)
Fri Oct 30 12:01:09 2015 : Debug: Module: Linked to module rlm_acct_unique
Fri Oct 30 12:01:09 2015 : Debug: Module: Instantiating acct_unique
Fri Oct 30 12:01:09 2015 : Debug: acct_unique {
Fri Oct 30 12:01:09 2015 : Debug: key = "User-Name, Acct-Session-Id, NAS-IP-Address, Client-IP-Address, NAS-Port"
Fri Oct 30 12:01:09 2015 : Debug: }
Fri Oct 30 12:01:09 2015 : Debug: Module: Checking accounting {...} for more modules to load
Fri Oct 30 12:01:09 2015 : Debug: (Loaded rlm_detail, checking if it's valid)
Fri Oct 30 12:01:09 2015 : Debug: Module: Linked to module rlm_detail
Fri Oct 30 12:01:09 2015 : Debug: Module: Instantiating detail
Fri Oct 30 12:01:09 2015 : Debug: detail {
Fri Oct 30 12:01:09 2015 : Debug: detailfile = "/var/log/radius/radacct/%{Client-IP-Address}/detail-%Y%m%d"
Fri Oct 30 12:01:09 2015 : Debug: header = "%t"
Fri Oct 30 12:01:09 2015 : Debug: detailperm = 384
Fri Oct 30 12:01:09 2015 : Debug: dirperm = 493
Fri Oct 30 12:01:09 2015 : Debug: locking = no
Fri Oct 30 12:01:09 2015 : Debug: log_packet_header = no
Fri Oct 30 12:01:09 2015 : Debug: }
Fri Oct 30 12:01:09 2015 : Debug: (Loaded rlm_unix, checking if it's valid)
Fri Oct 30 12:01:09 2015 : Debug: Module: Linked to module rlm_unix
Fri Oct 30 12:01:09 2015 : Debug: Module: Instantiating unix
Fri Oct 30 12:01:09 2015 : Debug: unix {
Fri Oct 30 12:01:09 2015 : Debug: radwtmp = "/var/log/radius/radwtmp"
Fri Oct 30 12:01:09 2015 : Debug: }
Fri Oct 30 12:01:09 2015 : Debug: Module: Instantiating attr_filter.accounting_response
Fri Oct 30 12:01:09 2015 : Debug: attr_filter attr_filter.accounting_response {
Fri Oct 30 12:01:09 2015 : Debug: attrsfile = "/etc/raddb/attrs.accounting_response"
Fri Oct 30 12:01:09 2015 : Debug: key = "%{User-Name}"
Fri Oct 30 12:01:09 2015 : Debug: }
Fri Oct 30 12:01:09 2015 : Debug: Module: Checking session {...} for more modules to load
Fri Oct 30 12:01:09 2015 : Debug: Module: Checking post-auth {...} for more modules to load
Fri Oct 30 12:01:09 2015 : Debug: }
Fri Oct 30 12:01:09 2015 : Debug: radiusd: #### Opening IP addresses and Ports ####
Fri Oct 30 12:01:09 2015 : Debug: listen {
Fri Oct 30 12:01:09 2015 : Debug: type = "auth"
Fri Oct 30 12:01:09 2015 : Debug: ipaddr = *
Fri Oct 30 12:01:09 2015 : Debug: port = 0
Fri Oct 30 12:01:09 2015 : Debug: }
Fri Oct 30 12:01:09 2015 : Debug: listen {
Fri Oct 30 12:01:09 2015 : Debug: type = "acct"
Fri Oct 30 12:01:09 2015 : Debug: ipaddr = *
Fri Oct 30 12:01:09 2015 : Debug: port = 0
Fri Oct 30 12:01:09 2015 : Debug: }
Fri Oct 30 12:01:09 2015 : Debug: listen {
Fri Oct 30 12:01:09 2015 : Debug: type = "auth"
Fri Oct 30 12:01:09 2015 : Debug: ipaddr = 127.0.0.1
Fri Oct 30 12:01:09 2015 : Debug: port = 18120
Fri Oct 30 12:01:09 2015 : Debug: }
Fri Oct 30 12:01:09 2015 : Debug: Listening on authentication address * port 1812
Fri Oct 30 12:01:09 2015 : Debug: Listening on accounting address * port 1813
Fri Oct 30 12:01:09 2015 : Debug: Listening on authentication address 127.0.0.1 port 18120 as server inner-tunnel
Fri Oct 30 12:01:09 2015 : Debug: Listening on proxy address * port 1814
Fri Oct 30 12:01:09 2015 : Debug: Ready to process requests.
rad_recv: Accounting-Request packet from host x.x.x.11 port 32839, id=114, length=199
Acct-Session-Id = "38724ED6-0000034A"
Acct-Status-Type = Stop
Acct-Authentic = Local
User-Name = "c0bdd1207464"
NAS-IP-Address = x.x.x.11
NAS-Identifier = "hello"
NAS-Port = 0
Called-Station-Id = "44-94-FC-96-4F-20:dacag"
Calling-Station-Id = "C0-BD-D1-20-74-64"
NAS-Port-Type = Wireless-802.11
Connect-Info = "CONNECT 0Mbps 802.11b"
Acct-Session-Time = 441
Acct-Input-Packets = 3960
Acct-Output-Packets = 6679
Acct-Input-Octets = 316751
Acct-Output-Octets = 9186656
Event-Timestamp = "Jan 14 2000 16:18:03 AST"
Acct-Terminate-Cause = User-Request
Fri Oct 30 12:02:17 2015 : Info: +- entering group preacct {...}
Fri Oct 30 12:02:17 2015 : Info: ++[preprocess] returns ok
Fri Oct 30 12:02:17 2015 : Info: [acct_unique] Hashing 'NAS-Port = 0,Client-IP-Address = x.x.x.11,NAS-IP-Address = x.x.x.11,Acct-Session-Id = "38724ED6-0000034A",User-Name = "c0bdd1207464"'
Fri Oct 30 12:02:17 2015 : Info: [acct_unique] Acct-Unique-Session-ID = "ff0403aade6cdfc0".
Fri Oct 30 12:02:17 2015 : Info: ++[acct_unique] returns ok
Fri Oct 30 12:02:17 2015 : Info: [suffix] No '@' in User-Name = "c0bdd1207464", looking up realm NULL
Fri Oct 30 12:02:17 2015 : Info: [suffix] No such realm "NULL"
Fri Oct 30 12:02:17 2015 : Info: ++[suffix] returns noop
Fri Oct 30 12:02:17 2015 : Info: ++[files] returns noop
Fri Oct 30 12:02:17 2015 : Info: +- entering group accounting {...}
Fri Oct 30 12:02:17 2015 : Info: [detail] expand: /var/log/radius/radacct/%{Client-IP-Address}/detail-%Y%m%d -> /var/log/radius/radacct/x.x.x.11/detail-20151030
Fri Oct 30 12:02:17 2015 : Info: [detail] /var/log/radius/radacct/%{Client-IP-Address}/detail-%Y%m%d expands to /var/log/radius/radacct/x.x.x.11/detail-20151030
Fri Oct 30 12:02:17 2015 : Info: [detail] expand: %t -> Fri Oct 30 12:02:17 2015
Fri Oct 30 12:02:17 2015 : Info: ++[detail] returns ok
Fri Oct 30 12:02:17 2015 : Info: ++[unix] returns ok
Fri Oct 30 12:02:17 2015 : Info: [radutmp] expand: /var/log/radius/radutmp -> /var/log/radius/radutmp
Fri Oct 30 12:02:17 2015 : Info: [radutmp] expand: %{User-Name} -> c0bdd1207464
Fri Oct 30 12:02:17 2015 : Error: rlm_radutmp: Logout entry for NAS AP1 port 0 has wrong ID
Fri Oct 30 12:02:17 2015 : Info: ++[radutmp] returns ok
Fri Oct 30 12:02:17 2015 : Info: [attr_filter.accounting_response] expand: %{User-Name} -> c0bdd1207464
Fri Oct 30 12:02:17 2015 : Debug: attr_filter: Matched entry DEFAULT at line 12
Fri Oct 30 12:02:17 2015 : Info: ++[attr_filter.accounting_response] returns updated
Sending Accounting-Response of id 114 to x.x.x.11 port 32839
Fri Oct 30 12:02:17 2015 : Info: Finished request 0.
Fri Oct 30 12:02:17 2015 : Info: Cleaning up request 0 ID 114 with timestamp +68
Fri Oct 30 12:02:17 2015 : Debug: Going to the next request
Fri Oct 30 12:02:17 2015 : Debug: Ready to process requests.
rad_recv: Access-Request packet from host x.x.x.11 port 32842, id=61, length=173
User-Name = "sur.name"
NAS-IP-Address = x.x.x.11
NAS-Identifier = "hello"
NAS-Port = 0
Called-Station-Id = "44-94-FC-96-4F-22:radiu"
Calling-Station-Id = "C0-BD-D1-20-74-64"
Framed-MTU = 1400
NAS-Port-Type = Wireless-802.11
Connect-Info = "CONNECT 0Mbps 802.11b"
EAP-Message = 0x020000130169676f722e626f7264656c616973
Message-Authenticator = 0x6c0c26f29491cc7bb6bf4bd3a77c947d
Fri Oct 30 12:02:17 2015 : Info: +- entering group authorize {...}
Fri Oct 30 12:02:17 2015 : Info: ++[preprocess] returns ok
Fri Oct 30 12:02:17 2015 : Info: [suffix] No '@' in User-Name = "sur.name", looking up realm NULL
Fri Oct 30 12:02:17 2015 : Info: [suffix] No such realm "NULL"
Fri Oct 30 12:02:17 2015 : Info: ++[suffix] returns noop
Fri Oct 30 12:02:17 2015 : Info: [eap] EAP packet type response id 0 length 19
Fri Oct 30 12:02:17 2015 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Fri Oct 30 12:02:17 2015 : Info: ++[eap] returns updated
Fri Oct 30 12:02:17 2015 : Info: [ldap] performing user authorization for sur.name
Fri Oct 30 12:02:17 2015 : Info: [ldap] WARNING: Deprecated conditional expansion ":-". See "man unlang" for details
Fri Oct 30 12:02:17 2015 : Info: [ldap] expand: (uid=%{Stripped-User-Name:-%{User-Name}}) -> (uid=sur.name)
Fri Oct 30 12:02:17 2015 : Info: [ldap] expand: dc=aviation-civile,dc=gouv,dc=fr -> dc=aviation-civile,dc=gouv,dc=fr
Fri Oct 30 12:02:17 2015 : Debug: rlm_ldap: ldap_get_conn: Checking Id: 0
Fri Oct 30 12:02:17 2015 : Debug: rlm_ldap: ldap_get_conn: Got Id: 0
Fri Oct 30 12:02:17 2015 : Debug: rlm_ldap: attempting LDAP reconnection
Fri Oct 30 12:02:17 2015 : Debug: rlm_ldap: (re)connect to x.x.x.246:389, authentication 0
Fri Oct 30 12:02:17 2015 : Debug: rlm_ldap: bind as uidNumber=1,sn=vvvvvv to x.x.x.x:389
Fri Oct 30 12:02:17 2015 : Debug: rlm_ldap: waiting for bind result ...
Fri Oct 30 12:02:17 2015 : Debug: rlm_ldap: Bind was successful
Fri Oct 30 12:02:17 2015 : Debug: rlm_ldap: performing search in dc=?, with filter (uid=sur,name)
Fri Oct 30 12:02:17 2015 : Info: [ldap] Added User-Password = {SSHA}RFTRrfI+1oC8H3znYttYUy7nkM6Z0gxKIOdInQ== in check items
Fri Oct 30 12:02:17 2015 : Info: [ldap] No default NMAS login sequence
Fri Oct 30 12:02:17 2015 : Info: [ldap] looking for check items in directory...
Fri Oct 30 12:02:17 2015 : Debug: rlm_ldap: userPassword -> Password-With-Header == "{SSHA}RFTRrfI+1oC8H3znYttYUy7nkM6Z0gxKIOdInQ=="
Fri Oct 30 12:02:17 2015 : Info: [ldap] looking for reply items in directory...
Fri Oct 30 12:02:17 2015 : Info: [ldap] user sur.name authorized to use remote access
Fri Oct 30 12:02:17 2015 : Debug: rlm_ldap: ldap_release_conn: Release Id: 0
Fri Oct 30 12:02:17 2015 : Info: ++[ldap] returns ok
Fri Oct 30 12:02:17 2015 : Info: ++[expiration] returns noop
Fri Oct 30 12:02:17 2015 : Info: ++[logintime] returns noop
Fri Oct 30 12:02:17 2015 : Info: [pap] Normalizing SSHA1-Password from base64 encoding
Fri Oct 30 12:02:17 2015 : Info: [pap] Normalizing SSHA1-Password from base64 encoding
Fri Oct 30 12:02:17 2015 : Info: [pap] Found existing Auth-Type, not changing it.
Fri Oct 30 12:02:17 2015 : Info: ++[pap] returns noop
Fri Oct 30 12:02:17 2015 : Info: Found Auth-Type = EAP
Fri Oct 30 12:02:17 2015 : Info: +- entering group authenticate {...}
Fri Oct 30 12:02:17 2015 : Info: [eap] EAP Identity
Fri Oct 30 12:02:17 2015 : Info: [eap] processing type tls
Fri Oct 30 12:02:17 2015 : Info: [tls] Initiate
Fri Oct 30 12:02:17 2015 : Info: [tls] Start returned 1
Fri Oct 30 12:02:17 2015 : Info: ++[eap] returns handled
Sending Access-Challenge of id 61 to x.x.x.11 port 32842
EAP-Message = 0x010100061520
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xfb55a41afb54b16008cc31758c0f388b
Fri Oct 30 12:02:17 2015 : Info: Finished request 1.
Fri Oct 30 12:02:17 2015 : Debug: Going to the next request
Fri Oct 30 12:02:17 2015 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host x.x.x.11 port 32842, id=62, length=376
User-Name = "sur.name"
NAS-IP-Address = x.x.x.11
NAS-Identifier = "hello"
NAS-Port = 0
Called-Station-Id = "44-94-FC-96-4F-22:radiu"
Calling-Station-Id = "C0-BD-D1-20-74-64"
Framed-MTU = 1400
NAS-Port-Type = Wireless-802.11
Connect-Info = "CONNECT 0Mbps 802.11b"
EAP-Message = 0x020100cc150016030100c1010000bd0301f7e68f620de4c71a1ec27a781228a010716b6e0c96358674b77c904328e2f374000054c014c00ac022c02100390038c00fc0050035c012c008c01cc01b00160013c00dc003000ac013c009c01fc01e00330032c00ec004002fc011c007c00cc002000500040015001200090014001100080006000300ff01000040000b000403000102000a00340032000e000d0019000b000c00180009000a00160017000800060007001400150004000500120013000100020003000f00100011
State = 0xfb55a41afb54b16008cc31758c0f388b
Message-Authenticator = 0x5df551af2f44dcee4fcd66101de8fba8
Fri Oct 30 12:02:17 2015 : Info: +- entering group authorize {...}
Fri Oct 30 12:02:17 2015 : Info: ++[preprocess] returns ok
Fri Oct 30 12:02:17 2015 : Info: [suffix] No '@' in User-Name = "sur.name", looking up realm NULL
Fri Oct 30 12:02:17 2015 : Info: [suffix] No such realm "NULL"
Fri Oct 30 12:02:17 2015 : Info: ++[suffix] returns noop
Fri Oct 30 12:02:17 2015 : Info: [eap] EAP packet type response id 1 length 204
Fri Oct 30 12:02:17 2015 : Info: [eap] Continuing tunnel setup.
Fri Oct 30 12:02:17 2015 : Info: ++[eap] returns ok
Fri Oct 30 12:02:17 2015 : Info: Found Auth-Type = EAP
Fri Oct 30 12:02:17 2015 : Info: +- entering group authenticate {...}
Fri Oct 30 12:02:17 2015 : Info: [eap] Request found, released from the list
Fri Oct 30 12:02:17 2015 : Info: [eap] EAP/ttls
Fri Oct 30 12:02:17 2015 : Info: [eap] processing type ttls
Fri Oct 30 12:02:17 2015 : Info: [ttls] Authenticate
Fri Oct 30 12:02:17 2015 : Info: [ttls] processing EAP-TLS
Fri Oct 30 12:02:17 2015 : Info: [ttls] eaptls_verify returned 7
Fri Oct 30 12:02:17 2015 : Info: [ttls] Done initial handshake
Fri Oct 30 12:02:17 2015 : Info: [ttls] (other): before/accept initialization
Fri Oct 30 12:02:17 2015 : Info: [ttls] TLS_accept: before/accept initialization
Fri Oct 30 12:02:17 2015 : Info: [ttls] <<< TLS 1.0 Handshake [length 00c1], ClientHello
Fri Oct 30 12:02:17 2015 : Info: [ttls] TLS_accept: SSLv3 read client hello A
Fri Oct 30 12:02:17 2015 : Info: [ttls]>>> TLS 1.0 Handshake [length 0031], ServerHello
Fri Oct 30 12:02:17 2015 : Info: [ttls] TLS_accept: SSLv3 write server hello A
Fri Oct 30 12:02:17 2015 : Info: [ttls]>>> TLS 1.0 Handshake [length 085e], Certificate
Fri Oct 30 12:02:17 2015 : Info: [ttls] TLS_accept: SSLv3 write certificate A
Fri Oct 30 12:02:17 2015 : Info: [ttls]>>> TLS 1.0 Handshake [length 020d], ServerKeyExchange
Fri Oct 30 12:02:17 2015 : Info: [ttls] TLS_accept: SSLv3 write key exchange A
Fri Oct 30 12:02:17 2015 : Info: [ttls]>>> TLS 1.0 Handshake [length 0004], ServerHelloDone
Fri Oct 30 12:02:17 2015 : Info: [ttls] TLS_accept: SSLv3 write server done A
Fri Oct 30 12:02:17 2015 : Info: [ttls] TLS_accept: SSLv3 flush data
Fri Oct 30 12:02:17 2015 : Info: [ttls] TLS_accept: Need to read more data: SSLv3 read client certificate A
Fri Oct 30 12:02:17 2015 : Debug: In SSL Handshake Phase
Fri Oct 30 12:02:17 2015 : Debug: In SSL Accept mode
Fri Oct 30 12:02:17 2015 : Info: [ttls] eaptls_process returned 13
Fri Oct 30 12:02:17 2015 : Info: ++[eap] returns handled
Sending Access-Challenge of id 62 to x.x.x.11 port 32842
EAP-Message = 0x0102040015c000000ab416030100310200002d0301563394891c80ada6f8f043a3a06584d6d17b8f761e2e66c5dbf3a2c311654e79000039000005ff01000100160301085e0b00085a0008570003a6308203a23082028aa003020102020101300d06092a864886f70d0101050500308193310b3009060355040613024652310f300d060355040813065261646975733112301006035504071309536f6d65776865726531153013060355040a130c4578616d706c6520496e632e3120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d312630240603550403131d4578616d706c65204365727469666963617465204175
EAP-Message = 0x74686f72697479301e170d3135303332363135323431355a170d3136303332353135323431355a307c310b3009060355040613024652310f300d0603550408130652616469757331153013060355040a130c4578616d706c6520496e632e312330210603550403131a4578616d706c65205365727665722043657274696669636174653120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d30820122300d06092a864886f70d01010105000382010f003082010a0282010100b844fff9a6811c3f38cdb467277a1c924d43a67b4877c4a66963b058d4a406deac5d604e7d5eaa6fa59099c0f057182823e697bf29c07c
EAP-Message = 0x3726501377ea6dbcbee2976f3886987f2e3bf4a3cb36f08ab23c7b2fb1b9692cca6c696795031a0810c393c88a367c007ee6ebccf84e3b4cc0786fef198f81f9b96230ee682fc9761be19fad8bf508fcb1b48e8ea4a39e09be76bbce24440d69b0d705f9ade67051a235583c2ee4a332a04d6d610f4c6e4c9a9cf38c9523e96baac9c9e3a6e96dba142fc38576453428f2d0442ac1d6d13ffe488f7857f79de4d82b90e0e6df121c08d9198313458da67a0750fdf62bab30937fb00f5a02c7a688ae95ad5e17c6959d0203010001a317301530130603551d25040c300a06082b06010505070301300d06092a864886f70d0101050500038201010043de
EAP-Message = 0x6e366c40df86b2154b222865d9359c7a604848ccedbd034ed063f639910c3b28858e1dbdf1ee7d86f8649741cd479260e9d62d707214570cfc6351053b9463505a863ac892074636cd34ff1b276f824d1dac5f074248e4e392d8ce414ed5a019ad45668bc0e683fdf1753b0cd6e36182d32f39c38b4ceb925a155a7c40b20ec20a1f1a95cf293d396360e2d2f96f65b09cccac9b972b3a1eb22aa194a4b5097c260c80457772463acf3ec095a93b08b3fd4797ad6ee3b9bc4322baf5e9e45eb69d2c48767bcc676147c3a8955128cea4595625bf5ef6c9520585b805b7b5f81a3f8ed7e82613e50388ea011215ba5779ea132244eca81f7d92f898733e
EAP-Message = 0x900004ab308204a73082038f
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xfb55a41afa57b16008cc31758c0f388b
Fri Oct 30 12:02:17 2015 : Info: Finished request 2.
Fri Oct 30 12:02:17 2015 : Debug: Going to the next request
Fri Oct 30 12:02:17 2015 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host x.x.x.11 port 32842, id=63, length=178
User-Name = "sur.name"
NAS-IP-Address = x.x.x.11
NAS-Identifier = "hello"
NAS-Port = 0
Called-Station-Id = "44-94-FC-96-4F-22:radiu"
Calling-Station-Id = "C0-BD-D1-20-74-64"
Framed-MTU = 1400
NAS-Port-Type = Wireless-802.11
Connect-Info = "CONNECT 0Mbps 802.11b"
EAP-Message = 0x020200061500
State = 0xfb55a41afa57b16008cc31758c0f388b
Message-Authenticator = 0x8d22ff59b913926e07b5af548aed67b6
Fri Oct 30 12:02:17 2015 : Info: +- entering group authorize {...}
Fri Oct 30 12:02:17 2015 : Info: ++[preprocess] returns ok
Fri Oct 30 12:02:17 2015 : Info: [suffix] No '@' in User-Name = "sur.name", looking up realm NULL
Fri Oct 30 12:02:17 2015 : Info: [suffix] No such realm "NULL"
Fri Oct 30 12:02:17 2015 : Info: ++[suffix] returns noop
Fri Oct 30 12:02:17 2015 : Info: [eap] EAP packet type response id 2 length 6
Fri Oct 30 12:02:17 2015 : Info: [eap] Continuing tunnel setup.
Fri Oct 30 12:02:17 2015 : Info: ++[eap] returns ok
Fri Oct 30 12:02:17 2015 : Info: Found Auth-Type = EAP
Fri Oct 30 12:02:17 2015 : Info: +- entering group authenticate {...}
Fri Oct 30 12:02:17 2015 : Info: [eap] Request found, released from the list
Fri Oct 30 12:02:17 2015 : Info: [eap] EAP/ttls
Fri Oct 30 12:02:17 2015 : Info: [eap] processing type ttls
Fri Oct 30 12:02:17 2015 : Info: [ttls] Authenticate
Fri Oct 30 12:02:17 2015 : Info: [ttls] processing EAP-TLS
Fri Oct 30 12:02:17 2015 : Info: [ttls] Received TLS ACK
Fri Oct 30 12:02:17 2015 : Info: [ttls] ACK handshake fragment handler
Fri Oct 30 12:02:17 2015 : Info: [ttls] eaptls_verify returned 1
Fri Oct 30 12:02:17 2015 : Info: [ttls] eaptls_process returned 13
Fri Oct 30 12:02:17 2015 : Info: ++[eap] returns handled
Sending Access-Challenge of id 63 to x.x.x.11 port 32842
EAP-Message = 0x0103040015c000000ab4a00302010202090093f94d5d0cac2aa0300d06092a864886f70d0101050500308193310b3009060355040613024652310f300d060355040813065261646975733112301006035504071309536f6d65776865726531153013060355040a130c4578616d706c6520496e632e3120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d312630240603550403131d4578616d706c6520436572746966696361746520417574686f72697479301e170d3135303332363135323431355a170d3135303432353135323431355a308193310b3009060355040613024652310f300d06035504081306526164
EAP-Message = 0x6975733112301006035504071309536f6d65776865726531153013060355040a130c4578616d706c6520496e632e3120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d312630240603550403131d4578616d706c6520436572746966696361746520417574686f7269747930820122300d06092a864886f70d01010105000382010f003082010a0282010100c49330b29b5e20134d7d3873ededd5517c1748f7f04f696842851ee613cb7fda1486278316b8d4066f0d4c4b8545b089797d06c54472b4dcb57b5d8adae391971c8ad4bee68b3d7e969b00187949f98080f6f51ed0905f55fce210fc8b2dc209ae6ee586
EAP-Message = 0xf5412475348fb499a6a333fa9f979659da60edae3cc14a60ea819fbcc72ca0c6240e3694da708bebc09d6e9c34b5267b22661d545eedd1fad36896880006f945152af6a946418496f521ab67d240399d4b61af37317bba906bd8876863173c6b509b02711f6d5e9c65d1b7f35308a70a8518e9768d1c00e5bd0ee4972a30aa9654e3f62bff52a5d76fc0e404d64b405cd60e9ac09fb85654704e27b90203010001a381fb3081f8301d0603551d0e04160414c54d0fa5259b04d3f9dd5d488dbb74243eee2e0b3081c80603551d230481c03081bd8014c54d0fa5259b04d3f9dd5d488dbb74243eee2e0ba18199a48196308193310b3009060355040613
EAP-Message = 0x024652310f300d060355040813065261646975733112301006035504071309536f6d65776865726531153013060355040a130c4578616d706c6520496e632e3120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d312630240603550403131d4578616d706c6520436572746966696361746520417574686f7269747982090093f94d5d0cac2aa0300c0603551d13040530030101ff300d06092a864886f70d01010505000382010100ad3711f91d43e677827d185b0529e2e97404d2a18be6fe250a6a38ff5ccf0f62019252b909420f09190f7cfd9e5565fe1f515cdc440a205a488330ef44a6ea4677cf888af6ba74
EAP-Message = 0x1d36debba53bf58769e47378
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xfb55a41af956b16008cc31758c0f388b
Fri Oct 30 12:02:17 2015 : Info: Finished request 3.
Fri Oct 30 12:02:17 2015 : Debug: Going to the next request
Fri Oct 30 12:02:17 2015 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host x.x.x.11 port 32842, id=64, length=178
User-Name = "sur.name"
NAS-IP-Address = x.x.x.11
NAS-Identifier = "hello"
NAS-Port = 0
Called-Station-Id = "44-94-FC-96-4F-22:radiu"
Calling-Station-Id = "C0-BD-D1-20-74-64"
Framed-MTU = 1400
NAS-Port-Type = Wireless-802.11
Connect-Info = "CONNECT 0Mbps 802.11b"
EAP-Message = 0x020300061500
State = 0xfb55a41af956b16008cc31758c0f388b
Message-Authenticator = 0x6d80b8ae19c36b0c3af449fc48d01c54
Fri Oct 30 12:02:17 2015 : Info: +- entering group authorize {...}
Fri Oct 30 12:02:17 2015 : Info: ++[preprocess] returns ok
Fri Oct 30 12:02:17 2015 : Info: [suffix] No '@' in User-Name = "sur.name", looking up realm NULL
Fri Oct 30 12:02:17 2015 : Info: [suffix] No such realm "NULL"
Fri Oct 30 12:02:17 2015 : Info: ++[suffix] returns noop
Fri Oct 30 12:02:17 2015 : Info: [eap] EAP packet type response id 3 length 6
Fri Oct 30 12:02:17 2015 : Info: [eap] Continuing tunnel setup.
Fri Oct 30 12:02:17 2015 : Info: ++[eap] returns ok
Fri Oct 30 12:02:17 2015 : Info: Found Auth-Type = EAP
Fri Oct 30 12:02:17 2015 : Info: +- entering group authenticate {...}
Fri Oct 30 12:02:17 2015 : Info: [eap] Request found, released from the list
Fri Oct 30 12:02:17 2015 : Info: [eap] EAP/ttls
Fri Oct 30 12:02:17 2015 : Info: [eap] processing type ttls
Fri Oct 30 12:02:17 2015 : Info: [ttls] Authenticate
Fri Oct 30 12:02:17 2015 : Info: [ttls] processing EAP-TLS
Fri Oct 30 12:02:17 2015 : Info: [ttls] Received TLS ACK
Fri Oct 30 12:02:17 2015 : Info: [ttls] ACK handshake fragment handler
Fri Oct 30 12:02:17 2015 : Info: [ttls] eaptls_verify returned 1
Fri Oct 30 12:02:17 2015 : Info: [ttls] eaptls_process returned 13
Fri Oct 30 12:02:17 2015 : Info: ++[eap] returns handled
Sending Access-Challenge of id 64 to x.x.x.11 port 32842
EAP-Message = 0x010402d2158000000ab4960410c0917b5819c4500b7b3d280f597fe3ae2e75e24c60caca11b8d738afdae08cc2780c9c8e6bc3daddc71e5f391660708818e07ac411c5bf247dda2fb09031fce4447f063d0a94e1d9e34c2493bb53d87618d83e4df56d65bc40b0750890de455d701fd53d617db91490ef004d91f4958ba07d01b3d055075d458892175106f5da4c162f14dc28f74db58b01964a209bfe64a00d4b33c7281359794c45e79ed847fcb49f7db23db2753dfe160301020d0c00020900808fc2fbaffcd9b4253135a756315c9cfa26ea2dc5565f917dafcbbdaa41c6750e7029757257161bf35a0a23306105f63c6848c1cce2e19ef12fa7aa
EAP-Message = 0x874ff3d792e3bf5eaa289bfb15f56a93b35cfbab6c088b15442f393ec4ae96ce0a6f3ba1be7c081e09dec793a5e779600bd271c64c71dc3f3a5b8bcefbbe6453c87506eb7b0001020080659d707ba691ec3b87d012471819a4f9d331c8611fc2ea10c37df8e888f9afb7cafcbbae864e3fd23944191230113d2227f1de20d45c658312fa2216287e9ac8b43c7dc2b801a8a90290ba4381347b3e33b9a39c674cc4f616e5409d38a0083e74e7a0bdd5475691ddb48c16fbf6bd2e2de0700d17d25e2e3207a81b198d114b01003f0f0bf04f3b3a3c547cdbce64f9f0a3ac0ce3c2e56ba0cff4e01610f28c01b7b8d116f6ae72ef69e2ac3a5998a09d8eeb
EAP-Message = 0xfd43b77418dd6276142c10d5de21d6a3423ebf349a2e432f19d0b54d29ac70b37b0d06fe8355c1819a919c868005d1cd7947d5ea510c544d40812ecbd7d597b6dc075177d931e152e0277dac5a33123170268bc988a0a29e66ca2ad2873c70ce640a5ddf98e6799ebc4e8a28b5b8e912402ac535fc3af0e7d840e8f7009b1a517101a496b9b3a3ea9c2b718cb35de3aac61703b848e02f2cd5fb196a6118e4fc0ab3fbad1f865dc79a4e6e91ba844dbf7e8c3cb8c1a3281508a9a6732240b1874a42d8baf91175577e862341a11f3b16030100040e000000
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xfb55a41af851b16008cc31758c0f388b
Fri Oct 30 12:02:17 2015 : Info: Finished request 4.
Fri Oct 30 12:02:17 2015 : Debug: Going to the next request
Fri Oct 30 12:02:17 2015 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host x.x.x.11 port 32842, id=65, length=376
User-Name = "sur.name"
NAS-IP-Address = x.x.x.11
NAS-Identifier = "hello"
NAS-Port = 0
Called-Station-Id = "44-94-FC-96-4F-22:radiu"
Calling-Station-Id = "C0-BD-D1-20-74-64"
Framed-MTU = 1400
NAS-Port-Type = Wireless-802.11
Connect-Info = "CONNECT 0Mbps 802.11b"
EAP-Message = 0x020400cc150016030100861000008200801e70c713da81c0055ec67136d17d29aa10789c988926167a8994545f99be6836c780ca887aac8e525790d1c09e7007671614fdfff8960834f6a0f3c04e44e648c06e4dbd5c3813fc5fbb2a7c127a13e58c78f6c814a466db187e536b7cec8395ee467dc0d8a6b0b3a309e6a87be7ba8764de3531a03f1e9d4e63261169ff4e2014030100010116030100307b905072b0db6679cba96b0ca4f862ad894a4d364075a95e783e425abe40b83f36b2f17ef580624769a7f83abfb6e606
State = 0xfb55a41af851b16008cc31758c0f388b
Message-Authenticator = 0x689fcf867d0bdcb5a3f4b8249d54cb65
Fri Oct 30 12:02:17 2015 : Info: +- entering group authorize {...}
Fri Oct 30 12:02:17 2015 : Info: ++[preprocess] returns ok
Fri Oct 30 12:02:17 2015 : Info: [suffix] No '@' in User-Name = "sur.name", looking up realm NULL
Fri Oct 30 12:02:17 2015 : Info: [suffix] No such realm "NULL"
Fri Oct 30 12:02:17 2015 : Info: ++[suffix] returns noop
Fri Oct 30 12:02:17 2015 : Info: [eap] EAP packet type response id 4 length 204
Fri Oct 30 12:02:17 2015 : Info: [eap] Continuing tunnel setup.
Fri Oct 30 12:02:17 2015 : Info: ++[eap] returns ok
Fri Oct 30 12:02:17 2015 : Info: Found Auth-Type = EAP
Fri Oct 30 12:02:17 2015 : Info: +- entering group authenticate {...}
Fri Oct 30 12:02:17 2015 : Info: [eap] Request found, released from the list
Fri Oct 30 12:02:17 2015 : Info: [eap] EAP/ttls
Fri Oct 30 12:02:17 2015 : Info: [eap] processing type ttls
Fri Oct 30 12:02:17 2015 : Info: [ttls] Authenticate
Fri Oct 30 12:02:17 2015 : Info: [ttls] processing EAP-TLS
Fri Oct 30 12:02:17 2015 : Info: [ttls] eaptls_verify returned 7
Fri Oct 30 12:02:17 2015 : Info: [ttls] Done initial handshake
Fri Oct 30 12:02:17 2015 : Info: [ttls] <<< TLS 1.0 Handshake [length 0086], ClientKeyExchange
Fri Oct 30 12:02:17 2015 : Info: [ttls] TLS_accept: SSLv3 read client key exchange A
Fri Oct 30 12:02:17 2015 : Info: [ttls] <<< TLS 1.0 ChangeCipherSpec [length 0001]
Fri Oct 30 12:02:17 2015 : Info: [ttls] <<< TLS 1.0 Handshake [length 0010], Finished
Fri Oct 30 12:02:17 2015 : Info: [ttls] TLS_accept: SSLv3 read finished A
Fri Oct 30 12:02:17 2015 : Info: [ttls]>>> TLS 1.0 ChangeCipherSpec [length 0001]
Fri Oct 30 12:02:17 2015 : Info: [ttls] TLS_accept: SSLv3 write change cipher spec A
Fri Oct 30 12:02:17 2015 : Info: [ttls]>>> TLS 1.0 Handshake [length 0010], Finished
Fri Oct 30 12:02:17 2015 : Info: [ttls] TLS_accept: SSLv3 write finished A
Fri Oct 30 12:02:17 2015 : Info: [ttls] TLS_accept: SSLv3 flush data
Fri Oct 30 12:02:17 2015 : Info: [ttls] (other): SSL negotiation finished successfully
Fri Oct 30 12:02:17 2015 : Debug: SSL Connection Established
Fri Oct 30 12:02:17 2015 : Info: [ttls] eaptls_process returned 13
Fri Oct 30 12:02:17 2015 : Info: ++[eap] returns handled
Sending Access-Challenge of id 65 to x.x.x.11 port 32842
EAP-Message = 0x0105004515800000003b1403010001011603010030b216c9f0153800a4fb9df076fc94527d87c55b3775ba38717c12b744e7a36e112c6aeb77b81845075a1e0a50140aa135
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xfb55a41aff50b16008cc31758c0f388b
Fri Oct 30 12:02:17 2015 : Info: Finished request 5.
Fri Oct 30 12:02:17 2015 : Debug: Going to the next request
Fri Oct 30 12:02:17 2015 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host x.x.x.11 port 32842, id=66, length=247
User-Name = "sur.name"
NAS-IP-Address = x.x.x.11
NAS-Identifier = "hello"
NAS-Port = 0
Called-Station-Id = "44-94-FC-96-4F-22:radiu"
Calling-Station-Id = "C0-BD-D1-20-74-64"
Framed-MTU = 1400
NAS-Port-Type = Wireless-802.11
Connect-Info = "CONNECT 0Mbps 802.11b"
EAP-Message = 0x0205004b150017030100402bf295aee05516623c3c5cd0a9ab238b3f9c3d2e1ff5e89b27efb66e3c1f8e1e50dbd4edd47da6946f0e4f1bde3352045124c3ed134890c8361591874bef582f
State = 0xfb55a41aff50b16008cc31758c0f388b
Message-Authenticator = 0x48419f6825d77b5e661183affc196bef
Fri Oct 30 12:02:17 2015 : Info: +- entering group authorize {...}
Fri Oct 30 12:02:17 2015 : Info: ++[preprocess] returns ok
Fri Oct 30 12:02:17 2015 : Info: [suffix] No '@' in User-Name = "sur.name", looking up realm NULL
Fri Oct 30 12:02:17 2015 : Info: [suffix] No such realm "NULL"
Fri Oct 30 12:02:17 2015 : Info: ++[suffix] returns noop
Fri Oct 30 12:02:17 2015 : Info: [eap] EAP packet type response id 5 length 75
Fri Oct 30 12:02:17 2015 : Info: [eap] Continuing tunnel setup.
Fri Oct 30 12:02:17 2015 : Info: ++[eap] returns ok
Fri Oct 30 12:02:17 2015 : Info: Found Auth-Type = EAP
Fri Oct 30 12:02:17 2015 : Info: +- entering group authenticate {...}
Fri Oct 30 12:02:17 2015 : Info: [eap] Request found, released from the list
Fri Oct 30 12:02:17 2015 : Info: [eap] EAP/ttls
Fri Oct 30 12:02:17 2015 : Info: [eap] processing type ttls
Fri Oct 30 12:02:17 2015 : Info: [ttls] Authenticate
Fri Oct 30 12:02:17 2015 : Info: [ttls] processing EAP-TLS
Fri Oct 30 12:02:17 2015 : Info: [ttls] eaptls_verify returned 7
Fri Oct 30 12:02:17 2015 : Info: [ttls] Done initial handshake
Fri Oct 30 12:02:17 2015 : Info: [ttls] eaptls_process returned 7
Fri Oct 30 12:02:17 2015 : Info: [ttls] Session established. Proceeding to decode tunneled attributes.
Fri Oct 30 12:02:17 2015 : Info: [ttls] Got tunneled request
EAP-Message = 0x020000130169676f722e626f7264656c616973
FreeRADIUS-Proxied-To = 127.0.0.1
Fri Oct 30 12:02:17 2015 : Info: [ttls] Got tunneled identity of sur.name
Fri Oct 30 12:02:17 2015 : Info: [ttls] Setting default EAP type for tunneled EAP session.
Fri Oct 30 12:02:17 2015 : Info: [ttls] Sending tunneled request
EAP-Message = 0x020000130169676f722e626f7264656c616973
FreeRADIUS-Proxied-To = 127.0.0.1
User-Name = "sur.name"
NAS-IP-Address = x.x.x.11
NAS-Identifier = "hello"
NAS-Port = 0
Called-Station-Id = "44-94-FC-96-4F-22:radiu"
Calling-Station-Id = "C0-BD-D1-20-74-64"
Framed-MTU = 1400
NAS-Port-Type = Wireless-802.11
Connect-Info = "CONNECT 0Mbps 802.11b"
server inner-tunnel {
Fri Oct 30 12:02:17 2015 : Info: +- entering group authorize {...}
Fri Oct 30 12:02:17 2015 : Info: [suffix] No '@' in User-Name = "sur.name", looking up realm NULL
Fri Oct 30 12:02:17 2015 : Info: [suffix] No such realm "NULL"
Fri Oct 30 12:02:17 2015 : Info: ++[suffix] returns noop
Fri Oct 30 12:02:17 2015 : Info: ++[control] returns noop
Fri Oct 30 12:02:17 2015 : Info: [eap] EAP packet type response id 0 length 19
Fri Oct 30 12:02:17 2015 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Fri Oct 30 12:02:17 2015 : Info: ++[eap] returns updated
Fri Oct 30 12:02:17 2015 : Info: ++[expiration] returns noop
Fri Oct 30 12:02:17 2015 : Info: ++[logintime] returns noop
Fri Oct 30 12:02:17 2015 : Info: ++[pap] returns noop
Fri Oct 30 12:02:17 2015 : Info: ++[mschap] returns noop
Fri Oct 30 12:02:17 2015 : Info: [suffix] No '@' in User-Name = "sur.name", looking up realm NULL
Fri Oct 30 12:02:17 2015 : Info: [suffix] No such realm "NULL"
Fri Oct 30 12:02:17 2015 : Info: ++[suffix] returns noop
Fri Oct 30 12:02:17 2015 : Info: ++[control] returns noop
Fri Oct 30 12:02:17 2015 : Info: [eap] EAP packet type response id 0 length 19
Fri Oct 30 12:02:17 2015 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Fri Oct 30 12:02:17 2015 : Info: ++[eap] returns updated
Fri Oct 30 12:02:17 2015 : Info: ++[files] returns noop
Fri Oct 30 12:02:17 2015 : Info: [ldap] performing user authorization for sur.name
Fri Oct 30 12:02:17 2015 : Info: [ldap] WARNING: Deprecated conditional expansion ":-". See "man unlang" for details
Fri Oct 30 12:02:17 2015 : Info: [ldap] expand: (uid=%{Stripped-User-Name:-%{User-Name}}) -> (uid=sur.name)
Fri Oct 30 12:02:17 2015 : Info: [ldap] expand: dc=aviation-civile,dc=gouv,dc=fr -> dc=aviation-civile,dc=gouv,dc=fr
Fri Oct 30 12:02:17 2015 : Debug: rlm_ldap: ldap_get_conn: Checking Id: 0
Fri Oct 30 12:02:17 2015 : Debug: rlm_ldap: ldap_get_conn: Got Id: 0
Fri Oct 30 12:02:17 2015 : Debug: rlm_ldap: performing search in dc=aviation-civile,dc=gouv,dc=fr, with filter (uid=sur.name)
Fri Oct 30 12:02:17 2015 : Info: [ldap] Added User-Password = {SSHA}RFTRrfI+1oC8H3znYttYUy7nkM6Z0gxKIOdInQ== in check items
Fri Oct 30 12:02:17 2015 : Info: [ldap] No default NMAS login sequence
Fri Oct 30 12:02:17 2015 : Info: [ldap] looking for check items in directory...
Fri Oct 30 12:02:17 2015 : Debug: rlm_ldap: userPassword -> Password-With-Header == "{SSHA}RFTRrfI+1oC8H3znYttYUy7nkM6Z0gxKIOdInQ=="
Fri Oct 30 12:02:17 2015 : Info: [ldap] looking for reply items in directory...
Fri Oct 30 12:02:17 2015 : Info: [ldap] user sur.name authorized to use remote access
Fri Oct 30 12:02:17 2015 : Debug: rlm_ldap: ldap_release_conn: Release Id: 0
Fri Oct 30 12:02:17 2015 : Info: ++[ldap] returns ok
Fri Oct 30 12:02:17 2015 : Info: ++[expiration] returns noop
Fri Oct 30 12:02:17 2015 : Info: ++[logintime] returns noop
Fri Oct 30 12:02:17 2015 : Info: [pap] Normalizing SSHA1-Password from base64 encoding
Fri Oct 30 12:02:17 2015 : Info: [pap] Normalizing SSHA1-Password from base64 encoding
Fri Oct 30 12:02:17 2015 : Info: [pap] Found existing Auth-Type, not changing it.
Fri Oct 30 12:02:17 2015 : Info: ++[pap] returns noop
Fri Oct 30 12:02:17 2015 : Info: Found Auth-Type = EAP
Fri Oct 30 12:02:17 2015 : Info: Found Auth-Type = EAP
Fri Oct 30 12:02:17 2015 : Error: Warning: Found 2 auth-types on request for user 'sur.name'
Fri Oct 30 12:02:17 2015 : Info: +- entering group authenticate {...}
Fri Oct 30 12:02:17 2015 : Info: [eap] EAP Identity
Fri Oct 30 12:02:17 2015 : Info: [eap] processing type gtc
Fri Oct 30 12:02:17 2015 : Info: ++[eap] returns handled
} # server inner-tunnel
Fri Oct 30 12:02:17 2015 : Info: [ttls] Got tunneled reply code 11
EAP-Message = 0x0101000f0650617373776f72643a20
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x549441c15495476ebe4ca443c855f2b0
Fri Oct 30 12:02:17 2015 : Info: [ttls] Got tunneled Access-Challenge
Fri Oct 30 12:02:17 2015 : Info: ++[eap] returns handled
Sending Access-Challenge of id 66 to x.x.x.11 port 32842
EAP-Message = 0x0106003f158000000035170301003015edd76419bfeb01075988592edd3df4960efb4226c5ea0862cdd579730acc8114521323ad642f22881c5f4a8b9d5f05
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xfb55a41afe53b16008cc31758c0f388b
Fri Oct 30 12:02:17 2015 : Info: Finished request 6.
Fri Oct 30 12:02:17 2015 : Debug: Going to the next request
Fri Oct 30 12:02:17 2015 : Debug: Waking up in 4.8 seconds.
Fri Oct 30 12:02:22 2015 : Info: Cleaning up request 1 ID 61 with timestamp +68
Fri Oct 30 12:02:22 2015 : Info: Cleaning up request 2 ID 62 with timestamp +68
Fri Oct 30 12:02:22 2015 : Info: Cleaning up request 3 ID 63 with timestamp +68
Fri Oct 30 12:02:22 2015 : Info: Cleaning up request 4 ID 64 with timestamp +68
Fri Oct 30 12:02:22 2015 : Info: Cleaning up request 5 ID 65 with timestamp +68
Fri Oct 30 12:02:22 2015 : Info: Cleaning up request 6 ID 66 with timestamp +68
Fri Oct 30 12:02:22 2015 : Debug: Ready to process requests.
rad_recv: Accounting-Request packet from host x.x.x.11 port 32839, id=115, length=157
Acct-Session-Id = "38724ED6-0000034B"
Acct-Status-Type = Start
Acct-Authentic = Local
User-Name = "c0bdd1207464"
NAS-IP-Address = x.x.x.11
NAS-Identifier = "hello"
NAS-Port = 0
Called-Station-Id = "44-94-FC-96-4F-20:dacag"
Calling-Station-Id = "C0-BD-D1-20-74-64"
NAS-Port-Type = Wireless-802.11
Connect-Info = "CONNECT 0Mbps 802.11b"
Fri Oct 30 12:02:39 2015 : Info: +- entering group preacct {...}
Fri Oct 30 12:02:39 2015 : Info: ++[preprocess] returns ok
Fri Oct 30 12:02:39 2015 : Info: [acct_unique] Hashing 'NAS-Port = 0,Client-IP-Address = x.x.x.11,NAS-IP-Address = x.x.x.11,Acct-Session-Id = "38724ED6-0000034B",User-Name = "c0bdd1207464"'
Fri Oct 30 12:02:39 2015 : Info: [acct_unique] Acct-Unique-Session-ID = "598f2bca49afa3c4".
Fri Oct 30 12:02:39 2015 : Info: ++[acct_unique] returns ok
Fri Oct 30 12:02:39 2015 : Info: [suffix] No '@' in User-Name = "c0bdd1207464", looking up realm NULL
Fri Oct 30 12:02:39 2015 : Info: [suffix] No such realm "NULL"
Fri Oct 30 12:02:39 2015 : Info: ++[suffix] returns noop
Fri Oct 30 12:02:39 2015 : Info: ++[files] returns noop
Fri Oct 30 12:02:39 2015 : Info: +- entering group accounting {...}
Fri Oct 30 12:02:39 2015 : Info: [detail] expand: /var/log/radius/radacct/%{Client-IP-Address}/detail-%Y%m%d -> /var/log/radius/radacct/x.x.x.11/detail-20151030
Fri Oct 30 12:02:39 2015 : Info: [detail] /var/log/radius/radacct/%{Client-IP-Address}/detail-%Y%m%d expands to /var/log/radius/radacct/x.x.x.11/detail-20151030
Fri Oct 30 12:02:39 2015 : Info: [detail] expand: %t -> Fri Oct 30 12:02:39 2015
Fri Oct 30 12:02:39 2015 : Info: ++[detail] returns ok
Fri Oct 30 12:02:39 2015 : Info: ++[unix] returns ok
Fri Oct 30 12:02:39 2015 : Info: [radutmp] expand: /var/log/radius/radutmp -> /var/log/radius/radutmp
Fri Oct 30 12:02:39 2015 : Info: [radutmp] expand: %{User-Name} -> c0bdd1207464
Fri Oct 30 12:02:39 2015 : Info: ++[radutmp] returns ok
Fri Oct 30 12:02:39 2015 : Info: [attr_filter.accounting_response] expand: %{User-Name} -> c0bdd1207464
Fri Oct 30 12:02:39 2015 : Debug: attr_filter: Matched entry DEFAULT at line 12
Fri Oct 30 12:02:39 2015 : Info: ++[attr_filter.accounting_response] returns updated
Sending Accounting-Response of id 115 to x.x.x.11 port 32839
Fri Oct 30 12:02:39 2015 : Info: Finished request 7.
Fri Oct 30 12:02:39 2015 : Info: Cleaning up request 7 ID 115 with timestamp +90
Fri Oct 30 12:02:39 2015 : Debug: Going to the next request
Fri Oct 30 12:02:39 2015 : Debug: Ready to process requests.
----------------------------------------
> Subject: Re: eap-ttls-gtc-pap
> From: aland at deployingradius.com
> Date: Fri, 30 Oct 2015 08:19:24 -0400
> To: freeradius-users at lists.freeradius.org
>
> On Oct 30, 2015, at 8:01 AM, Seike neg <seike at outlook.com> wrote:
>>
>> Hello I'm having trouble setting an eap-ttls-gtc-pap authentication against an LDAP server.
>> The PAP part is working without problem when I check it with radtest but i can't log with EAP-TTLS-GTC.
>> Anyone can help me please .
>> Thanks in advance.
>>
>> Here is my pastebin for my conf files:
>
> Can you explain why you're posting the configuration files, when the FAQ, "man" page, web pages, and daily messages on this list say to post the debug output?
>
> Where should we write "POST THE DEBUG OUTPUT" so that you will read it?
>
> Alan DeKok.
>
>
> -
> List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
More information about the Freeradius-Users
mailing list