freeradius update attributes in access-accept reply
Kiefer, Jonas
jonas.kiefer at classen.de
Tue Feb 23 16:27:03 CET 2016
Hello freeradius-users,
Iam running freeradius on ubuntu 14.04 LTS with mysql and daloradius.
Now i trie to authenticate a user via RADIUS on a Procurve Switch.
But the problem is that the configured service-type attribute are not send in the Access-Accept message.
Only in the Access-Challenge messages the attribute where send tot he procurve switch.
I need it in the Access-Accept reply message.
This is my logfile from the radiusserver:
Tue Feb 23 15:45:33 2016 : Info: FreeRADIUS Version 2.1.12, for host x86_64-pc-linux-gnu, built on Aug 26 2015 at 14:47:03
Tue Feb 23 15:45:33 2016 : Info: Copyright (C) 1999-2009 The FreeRADIUS server project and contributors.
Tue Feb 23 15:45:33 2016 : Info: There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A
Tue Feb 23 15:45:33 2016 : Info: PARTICULAR PURPOSE.
Tue Feb 23 15:45:33 2016 : Info: You may redistribute copies of FreeRADIUS under the terms of the
Tue Feb 23 15:45:33 2016 : Info: GNU General Public License v2.
Tue Feb 23 15:45:33 2016 : Info: Starting - reading configuration files ...
Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/radiusd.conf
Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/proxy.conf
Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/clients.conf
Tue Feb 23 15:45:33 2016 : Debug: including files in directory /etc/freeradius/modules/
Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/passwd
Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/sqlcounter_expire_on_login
Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/preprocess
Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/mschap
Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/radutmp
Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/smsotp
Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/sradutmp
Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/unix
Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/replicate
Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/smbpasswd
Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/detail
Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/checkval
Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/acct_unique
Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/wimax
Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/ntlm_auth
Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/files
Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/pap
Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/realm
Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/etc_group
Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/soh
Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/sql_log
Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/opendirectory
Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/perl
Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/detail.log
Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/mac2vlan
Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/echo
Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/linelog
Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/redis
Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/attr_filter
Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/chap
Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/mac2ip
Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/expiration
Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/digest
Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/attr_rewrite
Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/pam
Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/counter
Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/always
Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/cui
Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/logintime
Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/expr
Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/inner-eap
Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/detail.example.com
Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/ldap
Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/otp
Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/ippool
Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/dynamic_clients
Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/rediswho
Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/exec
Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/policy
Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/modules/krb5
Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/eap.conf
Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/sql.conf
Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/sql/mysql/dialup.conf
Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/sql/mysql/counter.conf
Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/policy.conf
Tue Feb 23 15:45:33 2016 : Debug: including files in directory /etc/freeradius/sites-enabled/
Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/sites-enabled/default
Tue Feb 23 15:45:33 2016 : Debug: including configuration file /etc/freeradius/sites-enabled/inner-tunnel
Tue Feb 23 15:45:33 2016 : Debug: main {
Tue Feb 23 15:45:33 2016 : Debug: user = "freerad"
Tue Feb 23 15:45:33 2016 : Debug: group = "freerad"
Tue Feb 23 15:45:33 2016 : Debug: allow_core_dumps = no
Tue Feb 23 15:45:33 2016 : Debug: }
Tue Feb 23 15:45:33 2016 : Debug: including dictionary file /etc/freeradius/dictionary
Tue Feb 23 15:45:33 2016 : Debug: main {
Tue Feb 23 15:45:33 2016 : Debug: name = "freeradius"
Tue Feb 23 15:45:33 2016 : Debug: prefix = "/usr"
Tue Feb 23 15:45:33 2016 : Debug: localstatedir = "/var"
Tue Feb 23 15:45:33 2016 : Debug: sbindir = "/usr/sbin"
Tue Feb 23 15:45:33 2016 : Debug: logdir = "/var/log/freeradius"
Tue Feb 23 15:45:33 2016 : Debug: run_dir = "/var/run/freeradius"
Tue Feb 23 15:45:33 2016 : Debug: libdir = "/usr/lib/freeradius"
Tue Feb 23 15:45:33 2016 : Debug: radacctdir = "/var/log/freeradius/radacct"
Tue Feb 23 15:45:33 2016 : Debug: hostname_lookups = no
Tue Feb 23 15:45:33 2016 : Debug: max_request_time = 30
Tue Feb 23 15:45:33 2016 : Debug: cleanup_delay = 5
Tue Feb 23 15:45:33 2016 : Debug: max_requests = 1024
Tue Feb 23 15:45:33 2016 : Debug: pidfile = "/var/run/freeradius/freeradius.pid"
Tue Feb 23 15:45:33 2016 : Debug: checkrad = "/usr/sbin/checkrad"
Tue Feb 23 15:45:33 2016 : Debug: debug_level = 0
Tue Feb 23 15:45:33 2016 : Debug: proxy_requests = yes
Tue Feb 23 15:45:33 2016 : Debug: log {
Tue Feb 23 15:45:33 2016 : Debug: stripped_names = no
Tue Feb 23 15:45:33 2016 : Debug: auth = no
Tue Feb 23 15:45:33 2016 : Debug: auth_badpass = no
Tue Feb 23 15:45:33 2016 : Debug: auth_goodpass = no
Tue Feb 23 15:45:33 2016 : Debug: }
Tue Feb 23 15:45:33 2016 : Debug: security {
Tue Feb 23 15:45:33 2016 : Debug: max_attributes = 200
Tue Feb 23 15:45:33 2016 : Debug: reject_delay = 1
Tue Feb 23 15:45:33 2016 : Debug: status_server = yes
Tue Feb 23 15:45:33 2016 : Debug: }
Tue Feb 23 15:45:33 2016 : Debug: }
Tue Feb 23 15:45:33 2016 : Debug: radiusd: #### Loading Realms and Home Servers ####
Tue Feb 23 15:45:33 2016 : Debug: proxy server {
Tue Feb 23 15:45:33 2016 : Debug: retry_delay = 5
Tue Feb 23 15:45:33 2016 : Debug: retry_count = 3
Tue Feb 23 15:45:33 2016 : Debug: default_fallback = no
Tue Feb 23 15:45:33 2016 : Debug: dead_time = 120
Tue Feb 23 15:45:33 2016 : Debug: wake_all_if_all_dead = no
Tue Feb 23 15:45:33 2016 : Debug: }
Tue Feb 23 15:45:33 2016 : Debug: home_server localhost {
Tue Feb 23 15:45:33 2016 : Debug: ipaddr = 127.0.0.1
Tue Feb 23 15:45:33 2016 : Debug: port = 1812
Tue Feb 23 15:45:33 2016 : Debug: type = "auth"
Tue Feb 23 15:45:33 2016 : Debug: secret = "testing123"
Tue Feb 23 15:45:33 2016 : Debug: response_window = 20
Tue Feb 23 15:45:33 2016 : Debug: max_outstanding = 65536
Tue Feb 23 15:45:33 2016 : Debug: require_message_authenticator = yes
Tue Feb 23 15:45:33 2016 : Debug: zombie_period = 40
Tue Feb 23 15:45:33 2016 : Debug: status_check = "status-server"
Tue Feb 23 15:45:33 2016 : Debug: ping_interval = 30
Tue Feb 23 15:45:33 2016 : Debug: check_interval = 30
Tue Feb 23 15:45:33 2016 : Debug: num_answers_to_alive = 3
Tue Feb 23 15:45:33 2016 : Debug: num_pings_to_alive = 3
Tue Feb 23 15:45:33 2016 : Debug: revive_interval = 120
Tue Feb 23 15:45:33 2016 : Debug: status_check_timeout = 4
Tue Feb 23 15:45:33 2016 : Debug: coa {
Tue Feb 23 15:45:33 2016 : Debug: irt = 2
Tue Feb 23 15:45:33 2016 : Debug: mrt = 16
Tue Feb 23 15:45:33 2016 : Debug: mrc = 5
Tue Feb 23 15:45:33 2016 : Debug: mrd = 30
Tue Feb 23 15:45:33 2016 : Debug: }
Tue Feb 23 15:45:33 2016 : Debug: }
Tue Feb 23 15:45:33 2016 : Debug: home_server_pool my_auth_failover {
Tue Feb 23 15:45:33 2016 : Debug: type = fail-over
Tue Feb 23 15:45:33 2016 : Debug: home_server = localhost
Tue Feb 23 15:45:33 2016 : Debug: }
Tue Feb 23 15:45:33 2016 : Debug: realm example.com {
Tue Feb 23 15:45:33 2016 : Debug: auth_pool = my_auth_failover
Tue Feb 23 15:45:33 2016 : Debug: }
Tue Feb 23 15:45:33 2016 : Debug: realm LOCAL {
Tue Feb 23 15:45:33 2016 : Debug: }
Tue Feb 23 15:45:33 2016 : Debug: radiusd: #### Loading Clients ####
Tue Feb 23 15:45:33 2016 : Debug: client localhost {
Tue Feb 23 15:45:33 2016 : Debug: ipaddr = 127.0.0.1
Tue Feb 23 15:45:33 2016 : Debug: require_message_authenticator = no
Tue Feb 23 15:45:33 2016 : Debug: secret = "testing123"
Tue Feb 23 15:45:33 2016 : Debug: nastype = "other"
Tue Feb 23 15:45:33 2016 : Debug: }
Tue Feb 23 15:45:33 2016 : Debug: radiusd: #### Instantiating modules ####
Tue Feb 23 15:45:33 2016 : Debug: instantiate {
Tue Feb 23 15:45:33 2016 : Debug: (Loaded rlm_exec, checking if it's valid)
Tue Feb 23 15:45:33 2016 : Debug: Module: Linked to module rlm_exec
Tue Feb 23 15:45:33 2016 : Debug: Module: Instantiating module "exec" from file /etc/freeradius/modules/exec
Tue Feb 23 15:45:33 2016 : Debug: exec {
Tue Feb 23 15:45:33 2016 : Debug: wait = no
Tue Feb 23 15:45:33 2016 : Debug: input_pairs = "request"
Tue Feb 23 15:45:33 2016 : Debug: shell_escape = yes
Tue Feb 23 15:45:33 2016 : Debug: }
Tue Feb 23 15:45:33 2016 : Debug: (Loaded rlm_expr, checking if it's valid)
Tue Feb 23 15:45:33 2016 : Debug: Module: Linked to module rlm_expr
Tue Feb 23 15:45:33 2016 : Debug: Module: Instantiating module "expr" from file /etc/freeradius/modules/expr
Tue Feb 23 15:45:33 2016 : Debug: (Loaded rlm_expiration, checking if it's valid)
Tue Feb 23 15:45:33 2016 : Debug: Module: Linked to module rlm_expiration
Tue Feb 23 15:45:33 2016 : Debug: Module: Instantiating module "expiration" from file /etc/freeradius/modules/expiration
Tue Feb 23 15:45:33 2016 : Debug: expiration {
Tue Feb 23 15:45:33 2016 : Debug: reply-message = "Password Has Expired "
Tue Feb 23 15:45:33 2016 : Debug: }
Tue Feb 23 15:45:33 2016 : Debug: (Loaded rlm_logintime, checking if it's valid)
Tue Feb 23 15:45:33 2016 : Debug: Module: Linked to module rlm_logintime
Tue Feb 23 15:45:33 2016 : Debug: Module: Instantiating module "logintime" from file /etc/freeradius/modules/logintime
Tue Feb 23 15:45:33 2016 : Debug: logintime {
Tue Feb 23 15:45:33 2016 : Debug: reply-message = "You are calling outside your allowed timespan "
Tue Feb 23 15:45:33 2016 : Debug: minimum-timeout = 60
Tue Feb 23 15:45:33 2016 : Debug: }
Tue Feb 23 15:45:33 2016 : Debug: }
Tue Feb 23 15:45:33 2016 : Debug: radiusd: #### Loading Virtual Servers ####
Tue Feb 23 15:45:33 2016 : Debug: server { # from file /etc/freeradius/radiusd.conf
Tue Feb 23 15:45:33 2016 : Debug: modules {
Tue Feb 23 15:45:33 2016 : Debug: Module: Creating Auth-Type = digest
Tue Feb 23 15:45:33 2016 : Debug: Module: Creating Post-Auth-Type = REJECT
Tue Feb 23 15:45:33 2016 : Debug: Module: Checking authenticate {...} for more modules to load
Tue Feb 23 15:45:33 2016 : Debug: (Loaded rlm_pap, checking if it's valid)
Tue Feb 23 15:45:33 2016 : Debug: Module: Linked to module rlm_pap
Tue Feb 23 15:45:33 2016 : Debug: Module: Instantiating module "pap" from file /etc/freeradius/modules/pap
Tue Feb 23 15:45:33 2016 : Debug: pap {
Tue Feb 23 15:45:33 2016 : Debug: encryption_scheme = "auto"
Tue Feb 23 15:45:33 2016 : Debug: auto_header = no
Tue Feb 23 15:45:33 2016 : Debug: }
Tue Feb 23 15:45:33 2016 : Debug: (Loaded rlm_chap, checking if it's valid)
Tue Feb 23 15:45:33 2016 : Debug: Module: Linked to module rlm_chap
Tue Feb 23 15:45:33 2016 : Debug: Module: Instantiating module "chap" from file /etc/freeradius/modules/chap
Tue Feb 23 15:45:33 2016 : Debug: (Loaded rlm_mschap, checking if it's valid)
Tue Feb 23 15:45:33 2016 : Debug: Module: Linked to module rlm_mschap
Tue Feb 23 15:45:33 2016 : Debug: Module: Instantiating module "mschap" from file /etc/freeradius/modules/mschap
Tue Feb 23 15:45:33 2016 : Debug: mschap {
Tue Feb 23 15:45:33 2016 : Debug: use_mppe = yes
Tue Feb 23 15:45:33 2016 : Debug: require_encryption = yes
Tue Feb 23 15:45:33 2016 : Debug: require_strong = yes
Tue Feb 23 15:45:33 2016 : Debug: with_ntdomain_hack = yes
Tue Feb 23 15:45:33 2016 : Debug: allow_retry = yes
Tue Feb 23 15:45:33 2016 : Debug: }
Tue Feb 23 15:45:33 2016 : Debug: (Loaded rlm_digest, checking if it's valid)
Tue Feb 23 15:45:33 2016 : Debug: Module: Linked to module rlm_digest
Tue Feb 23 15:45:33 2016 : Debug: Module: Instantiating module "digest" from file /etc/freeradius/modules/digest
Tue Feb 23 15:45:33 2016 : Debug: (Loaded rlm_unix, checking if it's valid)
Tue Feb 23 15:45:33 2016 : Debug: Module: Linked to module rlm_unix
Tue Feb 23 15:45:33 2016 : Debug: Module: Instantiating module "unix" from file /etc/freeradius/modules/unix
Tue Feb 23 15:45:33 2016 : Debug: unix {
Tue Feb 23 15:45:33 2016 : Debug: radwtmp = "/var/log/freeradius/radwtmp"
Tue Feb 23 15:45:33 2016 : Debug: }
Tue Feb 23 15:45:33 2016 : Debug: (Loaded rlm_eap, checking if it's valid)
Tue Feb 23 15:45:33 2016 : Debug: Module: Linked to module rlm_eap
Tue Feb 23 15:45:33 2016 : Debug: Module: Instantiating module "eap" from file /etc/freeradius/eap.conf
Tue Feb 23 15:45:33 2016 : Debug: eap {
Tue Feb 23 15:45:33 2016 : Debug: default_eap_type = "md5"
Tue Feb 23 15:45:33 2016 : Debug: timer_expire = 60
Tue Feb 23 15:45:33 2016 : Debug: ignore_unknown_eap_types = no
Tue Feb 23 15:45:33 2016 : Debug: cisco_accounting_username_bug = no
Tue Feb 23 15:45:33 2016 : Debug: max_sessions = 4096
Tue Feb 23 15:45:33 2016 : Debug: }
Tue Feb 23 15:45:33 2016 : Debug: Module: Linked to sub-module rlm_eap_md5
Tue Feb 23 15:45:33 2016 : Debug: Module: Instantiating eap-md5
Tue Feb 23 15:45:33 2016 : Debug: Module: Linked to sub-module rlm_eap_leap
Tue Feb 23 15:45:33 2016 : Debug: Module: Instantiating eap-leap
Tue Feb 23 15:45:33 2016 : Debug: Module: Linked to sub-module rlm_eap_gtc
Tue Feb 23 15:45:33 2016 : Debug: Module: Instantiating eap-gtc
Tue Feb 23 15:45:33 2016 : Debug: gtc {
Tue Feb 23 15:45:33 2016 : Debug: challenge = "Password: "
Tue Feb 23 15:45:33 2016 : Debug: auth_type = "PAP"
Tue Feb 23 15:45:33 2016 : Debug: }
Tue Feb 23 15:45:33 2016 : Debug: Module: Linked to sub-module rlm_eap_tls
Tue Feb 23 15:45:33 2016 : Debug: Module: Instantiating eap-tls
Tue Feb 23 15:45:33 2016 : Debug: tls {
Tue Feb 23 15:45:33 2016 : Debug: rsa_key_exchange = no
Tue Feb 23 15:45:33 2016 : Debug: dh_key_exchange = yes
Tue Feb 23 15:45:33 2016 : Debug: rsa_key_length = 512
Tue Feb 23 15:45:33 2016 : Debug: dh_key_length = 512
Tue Feb 23 15:45:33 2016 : Debug: verify_depth = 0
Tue Feb 23 15:45:33 2016 : Debug: CA_path = "/etc/freeradius/certs"
Tue Feb 23 15:45:33 2016 : Debug: pem_file_type = yes
Tue Feb 23 15:45:33 2016 : Debug: private_key_file = "/etc/freeradius/certs/server.key"
Tue Feb 23 15:45:33 2016 : Debug: certificate_file = "/etc/freeradius/certs/server.pem"
Tue Feb 23 15:45:33 2016 : Debug: CA_file = "/etc/freeradius/certs/ca.pem"
Tue Feb 23 15:45:33 2016 : Debug: private_key_password = "whatever"
Tue Feb 23 15:45:33 2016 : Debug: dh_file = "/etc/freeradius/certs/dh"
Tue Feb 23 15:45:33 2016 : Debug: random_file = "/dev/urandom"
Tue Feb 23 15:45:33 2016 : Debug: fragment_size = 1024
Tue Feb 23 15:45:33 2016 : Debug: include_length = yes
Tue Feb 23 15:45:33 2016 : Debug: check_crl = no
Tue Feb 23 15:45:33 2016 : Debug: cipher_list = "DEFAULT"
Tue Feb 23 15:45:33 2016 : Debug: make_cert_command = "/etc/freeradius/certs/bootstrap"
Tue Feb 23 15:45:33 2016 : Debug: ecdh_curve = "prime256v1"
Tue Feb 23 15:45:33 2016 : Debug: cache {
Tue Feb 23 15:45:33 2016 : Debug: enable = no
Tue Feb 23 15:45:33 2016 : Debug: lifetime = 24
Tue Feb 23 15:45:33 2016 : Debug: max_entries = 255
Tue Feb 23 15:45:33 2016 : Debug: }
Tue Feb 23 15:45:33 2016 : Debug: verify {
Tue Feb 23 15:45:33 2016 : Debug: }
Tue Feb 23 15:45:33 2016 : Debug: ocsp {
Tue Feb 23 15:45:33 2016 : Debug: enable = no
Tue Feb 23 15:45:33 2016 : Debug: override_cert_url = yes
Tue Feb 23 15:45:33 2016 : Debug: url = "http://127.0.0.1/ocsp/"
Tue Feb 23 15:45:33 2016 : Debug: }
Tue Feb 23 15:45:33 2016 : Debug: }
Tue Feb 23 15:45:33 2016 : Debug: Module: Linked to sub-module rlm_eap_ttls
Tue Feb 23 15:45:33 2016 : Debug: Module: Instantiating eap-ttls
Tue Feb 23 15:45:33 2016 : Debug: ttls {
Tue Feb 23 15:45:33 2016 : Debug: default_eap_type = "md5"
Tue Feb 23 15:45:33 2016 : Debug: copy_request_to_tunnel = no
Tue Feb 23 15:45:33 2016 : Debug: use_tunneled_reply = yes
Tue Feb 23 15:45:33 2016 : Debug: virtual_server = "inner-tunnel"
Tue Feb 23 15:45:33 2016 : Debug: include_length = yes
Tue Feb 23 15:45:33 2016 : Debug: }
Tue Feb 23 15:45:33 2016 : Debug: Module: Linked to sub-module rlm_eap_peap
Tue Feb 23 15:45:33 2016 : Debug: Module: Instantiating eap-peap
Tue Feb 23 15:45:33 2016 : Debug: peap {
Tue Feb 23 15:45:33 2016 : Debug: default_eap_type = "mschapv2"
Tue Feb 23 15:45:33 2016 : Debug: copy_request_to_tunnel = no
Tue Feb 23 15:45:33 2016 : Debug: use_tunneled_reply = yes
Tue Feb 23 15:45:33 2016 : Debug: proxy_tunneled_request_as_eap = yes
Tue Feb 23 15:45:33 2016 : Debug: virtual_server = "inner-tunnel"
Tue Feb 23 15:45:33 2016 : Debug: soh = no
Tue Feb 23 15:45:33 2016 : Debug: }
Tue Feb 23 15:45:33 2016 : Debug: Module: Linked to sub-module rlm_eap_mschapv2
Tue Feb 23 15:45:33 2016 : Debug: Module: Instantiating eap-mschapv2
Tue Feb 23 15:45:33 2016 : Debug: mschapv2 {
Tue Feb 23 15:45:33 2016 : Debug: with_ntdomain_hack = no
Tue Feb 23 15:45:33 2016 : Debug: send_error = no
Tue Feb 23 15:45:33 2016 : Debug: }
Tue Feb 23 15:45:33 2016 : Debug: Module: Checking authorize {...} for more modules to load
Tue Feb 23 15:45:33 2016 : Debug: (Loaded rlm_preprocess, checking if it's valid)
Tue Feb 23 15:45:33 2016 : Debug: Module: Linked to module rlm_preprocess
Tue Feb 23 15:45:33 2016 : Debug: Module: Instantiating module "preprocess" from file /etc/freeradius/modules/preprocess
Tue Feb 23 15:45:33 2016 : Debug: preprocess {
Tue Feb 23 15:45:33 2016 : Debug: huntgroups = "/etc/freeradius/huntgroups"
Tue Feb 23 15:45:33 2016 : Debug: hints = "/etc/freeradius/hints"
Tue Feb 23 15:45:33 2016 : Debug: with_ascend_hack = no
Tue Feb 23 15:45:33 2016 : Debug: ascend_channels_per_line = 23
Tue Feb 23 15:45:33 2016 : Debug: with_ntdomain_hack = no
Tue Feb 23 15:45:33 2016 : Debug: with_specialix_jetstream_hack = no
Tue Feb 23 15:45:33 2016 : Debug: with_cisco_vsa_hack = no
Tue Feb 23 15:45:33 2016 : Debug: with_alvarion_vsa_hack = no
Tue Feb 23 15:45:33 2016 : Debug: }
Tue Feb 23 15:45:33 2016 : Debug: (Loaded rlm_realm, checking if it's valid)
Tue Feb 23 15:45:33 2016 : Debug: Module: Linked to module rlm_realm
Tue Feb 23 15:45:33 2016 : Debug: Module: Instantiating module "suffix" from file /etc/freeradius/modules/realm
Tue Feb 23 15:45:33 2016 : Debug: realm suffix {
Tue Feb 23 15:45:33 2016 : Debug: format = "suffix"
Tue Feb 23 15:45:33 2016 : Debug: delimiter = "@"
Tue Feb 23 15:45:33 2016 : Debug: ignore_default = no
Tue Feb 23 15:45:33 2016 : Debug: ignore_null = no
Tue Feb 23 15:45:33 2016 : Debug: }
Tue Feb 23 15:45:33 2016 : Debug: (Loaded rlm_sql, checking if it's valid)
Tue Feb 23 15:45:33 2016 : Debug: Module: Linked to module rlm_sql
Tue Feb 23 15:45:33 2016 : Debug: Module: Instantiating module "sql" from file /etc/freeradius/sql.conf
Tue Feb 23 15:45:33 2016 : Debug: sql {
Tue Feb 23 15:45:33 2016 : Debug: driver = "rlm_sql_mysql"
Tue Feb 23 15:45:33 2016 : Debug: server = "localhost"
Tue Feb 23 15:45:33 2016 : Debug: port = ""
Tue Feb 23 15:45:33 2016 : Debug: login = "freeradius"
Tue Feb 23 15:45:33 2016 : Debug: password = "radius123"
Tue Feb 23 15:45:33 2016 : Debug: radius_db = "radius"
Tue Feb 23 15:45:33 2016 : Debug: read_groups = yes
Tue Feb 23 15:45:33 2016 : Debug: sqltrace = yes
Tue Feb 23 15:45:33 2016 : Debug: sqltracefile = "/var/log/freeradius/sqltrace.sql"
Tue Feb 23 15:45:33 2016 : Debug: readclients = yes
Tue Feb 23 15:45:33 2016 : Debug: deletestalesessions = yes
Tue Feb 23 15:45:33 2016 : Debug: num_sql_socks = 5
Tue Feb 23 15:45:33 2016 : Debug: lifetime = 0
Tue Feb 23 15:45:33 2016 : Debug: max_queries = 0
Tue Feb 23 15:45:33 2016 : Debug: sql_user_name = "%{User-Name}"
Tue Feb 23 15:45:33 2016 : Debug: default_user_profile = ""
Tue Feb 23 15:45:33 2016 : Debug: nas_query = "SELECT id, nasname, shortname, type, secret, server FROM nas"
Tue Feb 23 15:45:33 2016 : Debug: authorize_check_query = "SELECT id, username, attribute, value, op FROM radcheck WHERE username = '%{SQL-User-Name}' ORDER BY id"
Tue Feb 23 15:45:33 2016 : Debug: authorize_reply_query = "SELECT id, username, attribute, value, op FROM radreply WHERE username = '%{SQL-User-Name}' ORDER BY id"
Tue Feb 23 15:45:33 2016 : Debug: authorize_group_check_query = "SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = '%{Sql-Group}' ORDER BY id"
Tue Feb 23 15:45:33 2016 : Debug: authorize_group_reply_query = "SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = '%{Sql-Group}' ORDER BY id"
Tue Feb 23 15:45:33 2016 : Debug: accounting_onoff_query = " UPDATE radacct SET acctstoptime = '%S', acctsessiontime = unix_timestamp('%S') - unix_timestamp(acctstarttime), acctterminatecause = '%{Acct-Terminate-Cause}', acctstopdelay = %{%{Acct-Delay-Time}:-0} WHERE acctstoptime IS NULL AND nasipaddress = '%{NAS-IP-Address}' AND acctstarttime <= '%S'"
Tue Feb 23 15:45:33 2016 : Debug: accounting_update_query = " UPDATE radacct SET framedipaddress = '%{Framed-IP-Address}', acctsessiontime = '%{Acct-Session-Time}', acctinputoctets = '%{%{Acct-Input-Gigawords}:-0}' << 32 | '%{%{Acct-Input-Octets}:-0}', acctoutputoctets = '%{%{Acct-Output-Gigawords}:-0}' << 32 | '%{%{Acct-Output-Octets}:-0}' WHERE acctsessionid = '%{Acct-Session-Id}' AND username = '%{SQL-User-Name}' AND nasipaddress = '%{NAS-IP-Address}'"
Tue Feb 23 15:45:33 2016 : Debug: accounting_update_query_alt = " INSERT INTO radacct (acctsessionid, acctuniqueid, username, realm, nasipaddress, nasportid, nasporttype, acctstarttime, acctsessiontime, acctauthentic, connectinfo_start, acctinputoctets, acctoutputoctets, calledstationid, callingstationid, servicetype, framedprotocol, framedipaddress, acctstartdelay, xascendsessionsvrkey) VALUES ('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}', '%{SQL-User-Name}', '%{Realm}', '%{NAS-IP-Address}', '%{NAS-Port}', '%{NAS-Port-Type}', DATE_SUB('%S', INTERVAL (%{%{Acct-Session-Time}:-0} + %{%{Acct-Delay-Time}:-0}) SECOND), '%{Acct-Session-Time}', '%{Acct-Authentic}', '', '%{%{Acct-Input-Gigawords}:-0}' << 32 | '%{%{Acct-Input-Octets}:-0}', '%{%{Acct-Output-Gigawords}:-0}' << 32 | '%{%{Acct-Output-Octets}:-0}', '%{Called-Station-Id}', '%{Calling-Station-Id}', '%{Service-Type}', '%{Framed-Protocol}', '%{Framed-IP-Address}', '0', '%{X-Ascend-Session-Svr-Key}')"
Tue Feb 23 15:45:33 2016 : Debug: accounting_start_query = " INSERT INTO radacct (acctsessionid, acctuniqueid, username, realm, nasipaddress, nasportid, nasporttype, acctstarttime, acctstoptime, acctsessiontime, acctauthentic, connectinfo_start, connectinfo_stop, acctinputoctets, acctoutputoctets, calledstationid, callingstationid, acctterminatecause, servicetype, framedprotocol, framedipaddress, acctstartdelay, acctstopdelay, xascendsessionsvrkey) VALUES ('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}', '%{SQL-User-Name}', '%{Realm}', '%{NAS-IP-Address}', '%{NAS-Port}', '%{NAS-Port-Type}', '%S', NULL, '0', '%{Acct-Authentic}', '%{Connect-Info}', '', '0', '0', '%{Called-Station-Id}', '%{Calling-Station-Id}', '', '%{Service-Type}', '%{Framed-Protocol}', '%{Framed-IP-Address}', '%{%{Acct-Delay-Time}:-0}', '0', '%{X-Ascend-Session-Svr-Key}')"
Tue Feb 23 15:45:33 2016 : Debug: accounting_start_query_alt = " UPDATE radacct SET acctstarttime = '%S', acctstartdelay = '%{%{Acct-Delay-Time}:-0}', connectinfo_start = '%{Connect-Info}' WHERE acctsessionid = '%{Acct-Session-Id}' AND username = '%{SQL-User-Name}' AND nasipaddress = '%{NAS-IP-Address}'"
Tue Feb 23 15:45:33 2016 : Debug: accounting_stop_query = " UPDATE radacct SET acctstoptime = '%S', acctsessiontime = '%{Acct-Session-Time}', acctinputoctets = '%{%{Acct-Input-Gigawords}:-0}' << 32 | '%{%{Acct-Input-Octets}:-0}', acctoutputoctets = '%{%{Acct-Output-Gigawords}:-0}' << 32 | '%{%{Acct-Output-Octets}:-0}', acctterminatecause = '%{Acct-Terminate-Cause}', acctstopdelay = '%{%{Acct-Delay-Time}:-0}', connectinfo_stop = '%{Connect-Info}' WHERE acctsessionid = '%{Acct-Session-Id}' AND username = '%{SQL-User-Name}' AND nasipaddress = '%{NAS-IP-Address}'"
Tue Feb 23 15:45:33 2016 : Debug: accounting_stop_query_alt = " INSERT INTO radacct (acctsessionid, acctuniqueid, username, realm, nasipaddress, nasportid, nasporttype, acctstarttime, acctstoptime, acctsessiontime, acctauthentic, connectinfo_start, connectinfo_stop, acctinputoctets, acctoutputoctets, calledstationid, callingstationid, acctterminatecause, servicetype, framedprotocol, framedipaddress, acctstartdelay, acctstopdelay) VALUES ('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}', '%{SQL-User-Name}', '%{Realm}', '%{NAS-IP-Address}', '%{NAS-Port}', '%{NAS-Port-Type}', DATE_SUB('%S', INTERVAL (%{%{Acct-Session-Time}:-0} + %{%{Acct-Delay-Time}:-0}) SECOND), '%S', '%{Acct-Session-Time}', '%{Acct-Authentic}', '', '%{Connect-Info}', '%{%{Acct-Input-Gigawords}:-0}' << 32 | '%{%{Acct-Input-Octets}:-0}', '%{%{Acct-Output-Gigawords}:-0}' << 32 | '%{%{Acct-Output-Octets}:-0}', '%{Called-Station-Id}', '%{Calling-Station-Id}', '%{Acct-Terminate-Cause}', '%{Service-Type}', '%{Framed-Protocol}', '%{Framed-IP-Address}', '0', '%{%{Acct-Delay-Time}:-0}')"
Tue Feb 23 15:45:33 2016 : Debug: group_membership_query = "SELECT groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority"
Tue Feb 23 15:45:33 2016 : Debug: connect_failure_retry_delay = 60
Tue Feb 23 15:45:33 2016 : Debug: simul_count_query = ""
Tue Feb 23 15:45:33 2016 : Debug: simul_verify_query = "SELECT radacctid, acctsessionid, username, nasipaddress, nasportid, framedipaddress, callingstationid, framedprotocol FROM radacct WHERE username = '%{SQL-User-Name}' AND acctstoptime IS NULL"
Tue Feb 23 15:45:33 2016 : Debug: postauth_query = "INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '%{User-Name}', '%{%{User-Password}:-%{Chap-Password}}', '%{reply:Packet-Type}', '%S')"
Tue Feb 23 15:45:33 2016 : Debug: safe-characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /"
Tue Feb 23 15:45:33 2016 : Debug: }
Tue Feb 23 15:45:33 2016 : Info: rlm_sql (sql): Driver rlm_sql_mysql (module rlm_sql_mysql) loaded and linked
Tue Feb 23 15:45:33 2016 : Info: rlm_sql (sql): Attempting to connect to freeradius at localhost:/radius
Tue Feb 23 15:45:33 2016 : Debug: rlm_sql (sql): starting 0
Tue Feb 23 15:45:33 2016 : Info: rlm_sql (sql): Attempting to connect rlm_sql_mysql #0
Tue Feb 23 15:45:33 2016 : Info: rlm_sql_mysql: Starting connect to MySQL server for #0
Tue Feb 23 15:45:33 2016 : Info: rlm_sql (sql): Connected new DB handle, #0
Tue Feb 23 15:45:33 2016 : Debug: rlm_sql (sql): starting 1
Tue Feb 23 15:45:33 2016 : Info: rlm_sql (sql): Attempting to connect rlm_sql_mysql #1
Tue Feb 23 15:45:33 2016 : Info: rlm_sql_mysql: Starting connect to MySQL server for #1
Tue Feb 23 15:45:33 2016 : Info: rlm_sql (sql): Connected new DB handle, #1
Tue Feb 23 15:45:33 2016 : Debug: rlm_sql (sql): starting 2
Tue Feb 23 15:45:33 2016 : Info: rlm_sql (sql): Attempting to connect rlm_sql_mysql #2
Tue Feb 23 15:45:33 2016 : Info: rlm_sql_mysql: Starting connect to MySQL server for #2
Tue Feb 23 15:45:33 2016 : Info: rlm_sql (sql): Connected new DB handle, #2
Tue Feb 23 15:45:33 2016 : Debug: rlm_sql (sql): starting 3
Tue Feb 23 15:45:33 2016 : Info: rlm_sql (sql): Attempting to connect rlm_sql_mysql #3
Tue Feb 23 15:45:33 2016 : Info: rlm_sql_mysql: Starting connect to MySQL server for #3
Tue Feb 23 15:45:33 2016 : Info: rlm_sql (sql): Connected new DB handle, #3
Tue Feb 23 15:45:33 2016 : Debug: rlm_sql (sql): starting 4
Tue Feb 23 15:45:33 2016 : Info: rlm_sql (sql): Attempting to connect rlm_sql_mysql #4
Tue Feb 23 15:45:33 2016 : Info: rlm_sql_mysql: Starting connect to MySQL server for #4
Tue Feb 23 15:45:33 2016 : Info: rlm_sql (sql): Connected new DB handle, #4
Tue Feb 23 15:45:33 2016 : Debug: rlm_sql (sql): Processing generate_sql_clients
Tue Feb 23 15:45:33 2016 : Debug: rlm_sql (sql) in generate_sql_clients: query is SELECT id, nasname, shortname, type, secret, server FROM nas
Tue Feb 23 15:45:33 2016 : Debug: rlm_sql (sql): Reserving sql socket id: 4
Tue Feb 23 15:45:33 2016 : Debug: rlm_sql_mysql: query: SELECT id, nasname, shortname, type, secret, server FROM nas
Tue Feb 23 15:45:33 2016 : Debug: rlm_sql (sql): Read entry nasname=192.168.6.211,shortname=test,secret=radius123
Tue Feb 23 15:45:33 2016 : Debug: rlm_sql (sql): Adding client 192.168.6.211 (test, server=<none>) to clients list
Tue Feb 23 15:45:33 2016 : Debug: rlm_sql (sql): Released sql socket id: 4
Tue Feb 23 15:45:33 2016 : Debug: Module: Checking preacct {...} for more modules to load
Tue Feb 23 15:45:33 2016 : Debug: (Loaded rlm_acct_unique, checking if it's valid)
Tue Feb 23 15:45:33 2016 : Debug: Module: Linked to module rlm_acct_unique
Tue Feb 23 15:45:33 2016 : Debug: Module: Instantiating module "acct_unique" from file /etc/freeradius/modules/acct_unique
Tue Feb 23 15:45:33 2016 : Debug: acct_unique {
Tue Feb 23 15:45:33 2016 : Debug: key = "User-Name, Acct-Session-Id, NAS-IP-Address, Client-IP-Address, NAS-Port"
Tue Feb 23 15:45:33 2016 : Debug: }
Tue Feb 23 15:45:33 2016 : Debug: (Loaded rlm_files, checking if it's valid)
Tue Feb 23 15:45:33 2016 : Debug: Module: Linked to module rlm_files
Tue Feb 23 15:45:33 2016 : Debug: Module: Instantiating module "files" from file /etc/freeradius/modules/files
Tue Feb 23 15:45:33 2016 : Debug: files {
Tue Feb 23 15:45:33 2016 : Debug: usersfile = "/etc/freeradius/users"
Tue Feb 23 15:45:33 2016 : Debug: acctusersfile = "/etc/freeradius/acct_users"
Tue Feb 23 15:45:33 2016 : Debug: preproxy_usersfile = "/etc/freeradius/preproxy_users"
Tue Feb 23 15:45:33 2016 : Debug: compat = "no"
Tue Feb 23 15:45:33 2016 : Debug: }
Tue Feb 23 15:45:33 2016 : Debug: Module: Checking accounting {...} for more modules to load
Tue Feb 23 15:45:33 2016 : Debug: (Loaded rlm_detail, checking if it's valid)
Tue Feb 23 15:45:33 2016 : Debug: Module: Linked to module rlm_detail
Tue Feb 23 15:45:33 2016 : Debug: Module: Instantiating module "detail" from file /etc/freeradius/modules/detail
Tue Feb 23 15:45:33 2016 : Debug: detail {
Tue Feb 23 15:45:33 2016 : Debug: detailfile = "/var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d"
Tue Feb 23 15:45:33 2016 : Debug: header = "%t"
Tue Feb 23 15:45:33 2016 : Debug: detailperm = 384
Tue Feb 23 15:45:33 2016 : Debug: dirperm = 493
Tue Feb 23 15:45:33 2016 : Debug: locking = no
Tue Feb 23 15:45:33 2016 : Debug: log_packet_header = no
Tue Feb 23 15:45:33 2016 : Debug: }
Tue Feb 23 15:45:33 2016 : Debug: (Loaded rlm_radutmp, checking if it's valid)
Tue Feb 23 15:45:33 2016 : Debug: Module: Linked to module rlm_radutmp
Tue Feb 23 15:45:33 2016 : Debug: Module: Instantiating module "radutmp" from file /etc/freeradius/modules/radutmp
Tue Feb 23 15:45:33 2016 : Debug: radutmp {
Tue Feb 23 15:45:33 2016 : Debug: filename = "/var/log/freeradius/radutmp"
Tue Feb 23 15:45:33 2016 : Debug: username = "%{User-Name}"
Tue Feb 23 15:45:33 2016 : Debug: case_sensitive = yes
Tue Feb 23 15:45:33 2016 : Debug: check_with_nas = yes
Tue Feb 23 15:45:33 2016 : Debug: perm = 384
Tue Feb 23 15:45:33 2016 : Debug: callerid = yes
Tue Feb 23 15:45:33 2016 : Debug: }
Tue Feb 23 15:45:33 2016 : Debug: (Loaded rlm_attr_filter, checking if it's valid)
Tue Feb 23 15:45:33 2016 : Debug: Module: Linked to module rlm_attr_filter
Tue Feb 23 15:45:33 2016 : Debug: Module: Instantiating module "attr_filter.accounting_response" from file /etc/freeradius/modules/attr_filter
Tue Feb 23 15:45:33 2016 : Debug: attr_filter attr_filter.accounting_response {
Tue Feb 23 15:45:33 2016 : Debug: attrsfile = "/etc/freeradius/attrs.accounting_response"
Tue Feb 23 15:45:33 2016 : Debug: key = "%{User-Name}"
Tue Feb 23 15:45:33 2016 : Debug: relaxed = no
Tue Feb 23 15:45:33 2016 : Debug: }
Tue Feb 23 15:45:33 2016 : Debug: Module: Checking session {...} for more modules to load
Tue Feb 23 15:45:33 2016 : Debug: Module: Checking post-proxy {...} for more modules to load
Tue Feb 23 15:45:33 2016 : Debug: Module: Checking post-auth {...} for more modules to load
Tue Feb 23 15:45:33 2016 : Debug: Module: Instantiating module "attr_filter.access_reject" from file /etc/freeradius/modules/attr_filter
Tue Feb 23 15:45:33 2016 : Debug: attr_filter attr_filter.access_reject {
Tue Feb 23 15:45:33 2016 : Debug: attrsfile = "/etc/freeradius/attrs.access_reject"
Tue Feb 23 15:45:33 2016 : Debug: key = "%{User-Name}"
Tue Feb 23 15:45:33 2016 : Debug: relaxed = no
Tue Feb 23 15:45:33 2016 : Debug: }
Tue Feb 23 15:45:33 2016 : Debug: } # modules
Tue Feb 23 15:45:33 2016 : Debug: } # server
Tue Feb 23 15:45:33 2016 : Debug: server inner-tunnel { # from file /etc/freeradius/sites-enabled/inner-tunnel
Tue Feb 23 15:45:33 2016 : Debug: modules {
Tue Feb 23 15:45:33 2016 : Debug: Module: Checking authenticate {...} for more modules to load
Tue Feb 23 15:45:33 2016 : Debug: Module: Checking authorize {...} for more modules to load
Tue Feb 23 15:45:33 2016 : Debug: Module: Checking session {...} for more modules to load
Tue Feb 23 15:45:33 2016 : Debug: Module: Checking post-proxy {...} for more modules to load
Tue Feb 23 15:45:33 2016 : Debug: Module: Checking post-auth {...} for more modules to load
Tue Feb 23 15:45:33 2016 : Debug: } # modules
Tue Feb 23 15:45:33 2016 : Debug: } # server
Tue Feb 23 15:45:33 2016 : Debug: radiusd: #### Opening IP addresses and Ports ####
Tue Feb 23 15:45:33 2016 : Debug: listen {
Tue Feb 23 15:45:33 2016 : Debug: type = "auth"
Tue Feb 23 15:45:33 2016 : Debug: ipaddr = *
Tue Feb 23 15:45:33 2016 : Debug: port = 0
Tue Feb 23 15:45:33 2016 : Debug: }
Tue Feb 23 15:45:33 2016 : Debug: listen {
Tue Feb 23 15:45:33 2016 : Debug: type = "acct"
Tue Feb 23 15:45:33 2016 : Debug: ipaddr = *
Tue Feb 23 15:45:33 2016 : Debug: port = 0
Tue Feb 23 15:45:33 2016 : Debug: }
Tue Feb 23 15:45:33 2016 : Debug: listen {
Tue Feb 23 15:45:33 2016 : Debug: type = "auth"
Tue Feb 23 15:45:33 2016 : Debug: ipaddr = 127.0.0.1
Tue Feb 23 15:45:33 2016 : Debug: port = 18120
Tue Feb 23 15:45:33 2016 : Debug: }
Tue Feb 23 15:45:33 2016 : Info: ... adding new socket proxy address * port 54611
Tue Feb 23 15:45:33 2016 : Debug: Listening on authentication address * port 1812
Tue Feb 23 15:45:33 2016 : Debug: Listening on accounting address * port 1813
Tue Feb 23 15:45:33 2016 : Debug: Listening on authentication address 127.0.0.1 port 18120 as server inner-tunnel
Tue Feb 23 15:45:33 2016 : Debug: Listening on proxy address * port 1814
Tue Feb 23 15:45:33 2016 : Info: Ready to process requests.
rad_recv: Access-Request packet from host 192.168.6.211 port 1812, id=142, length=116
User-Name = "1234"
NAS-IP-Address = 211.6.168.192
NAS-Identifier = "SWITCH01-TEST"
NAS-Port-Type = Virtual
Service-Type = NAS-Prompt-User
EAP-Message = 0x020000090131323334
Message-Authenticator = 0x17ebe7cb3727cfa3b2fde0893d30241a
MS-RAS-Vendor = 184549376
Calling-Station-Id = "192.168.14.114"
Tue Feb 23 15:45:41 2016 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default
Tue Feb 23 15:45:41 2016 : Info: +- entering group authorize {...}
Tue Feb 23 15:45:41 2016 : Info: ++[preprocess] returns ok
Tue Feb 23 15:45:41 2016 : Info: ++[chap] returns noop
Tue Feb 23 15:45:41 2016 : Info: ++[mschap] returns noop
Tue Feb 23 15:45:41 2016 : Info: ++[digest] returns noop
Tue Feb 23 15:45:41 2016 : Info: [suffix] No '@' in User-Name = "1234", looking up realm NULL
Tue Feb 23 15:45:41 2016 : Info: [suffix] No such realm "NULL"
Tue Feb 23 15:45:41 2016 : Info: ++[suffix] returns noop
Tue Feb 23 15:45:41 2016 : Info: [eap] EAP packet type response id 0 length 9
Tue Feb 23 15:45:41 2016 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Tue Feb 23 15:45:41 2016 : Info: ++[eap] returns updated
Tue Feb 23 15:45:41 2016 : Info: [sql] expand: %{User-Name} -> 1234
Tue Feb 23 15:45:41 2016 : Info: [sql] sql_set_user escaped user --> '1234'
Tue Feb 23 15:45:41 2016 : Debug: rlm_sql (sql): Reserving sql socket id: 3
Tue Feb 23 15:45:41 2016 : Info: [sql] expand: SELECT id, username, attribute, value, op FROM radcheck WHERE username = '%{SQL-User-Name}' ORDER BY id -> SELECT id, username, attribute, value, op FROM radcheck WHERE username = '1234' ORDER BY id
Tue Feb 23 15:45:41 2016 : Debug: rlm_sql_mysql: query: SELECT id, username, attribute, value, op FROM radcheck WHERE username = '1234' ORDER BY id
Tue Feb 23 15:45:41 2016 : Info: [sql] User found in radcheck table
Tue Feb 23 15:45:41 2016 : Info: [sql] expand: SELECT id, username, attribute, value, op FROM radreply WHERE username = '%{SQL-User-Name}' ORDER BY id -> SELECT id, username, attribute, value, op FROM radreply WHERE username = '1234' ORDER BY id
Tue Feb 23 15:45:41 2016 : Debug: rlm_sql_mysql: query: SELECT id, username, attribute, value, op FROM radreply WHERE username = '1234' ORDER BY id
Tue Feb 23 15:45:41 2016 : Info: [sql] expand: SELECT groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority -> SELECT groupname FROM radusergroup WHERE username = '1234' ORDER BY priority
Tue Feb 23 15:45:41 2016 : Debug: rlm_sql_mysql: query: SELECT groupname FROM radusergroup WHERE username = '1234' ORDER BY priority
Tue Feb 23 15:45:41 2016 : Info: [sql] expand: SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = '%{Sql-Group}' ORDER BY id -> SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = 'HP-Procurve-Admin' ORDER BY id
Tue Feb 23 15:45:41 2016 : Debug: rlm_sql_mysql: query: SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = 'HP-Procurve-Admin' ORDER BY id
Tue Feb 23 15:45:41 2016 : Info: [sql] User found in group HP-Procurve-Admin
Tue Feb 23 15:45:41 2016 : Info: [sql] expand: SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = '%{Sql-Group}' ORDER BY id -> SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = 'HP-Procurve-Admin' ORDER BY id
Tue Feb 23 15:45:41 2016 : Debug: rlm_sql_mysql: query: SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = 'HP-Procurve-Admin' ORDER BY id
Tue Feb 23 15:45:41 2016 : Debug: rlm_sql (sql): Released sql socket id: 3
Tue Feb 23 15:45:41 2016 : Info: ++[sql] returns ok
Tue Feb 23 15:45:41 2016 : Info: ++[expiration] returns noop
Tue Feb 23 15:45:41 2016 : Info: ++[logintime] returns noop
Tue Feb 23 15:45:41 2016 : Info: [pap] WARNING: Auth-Type already set. Not setting to PAP
Tue Feb 23 15:45:41 2016 : Info: ++[pap] returns noop
Tue Feb 23 15:45:41 2016 : Info: Found Auth-Type = EAP
Tue Feb 23 15:45:41 2016 : Info: !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
Tue Feb 23 15:45:41 2016 : Info: !!! Replacing User-Password in config items with Cleartext-Password. !!!
Tue Feb 23 15:45:41 2016 : Info: !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
Tue Feb 23 15:45:41 2016 : Info: !!! Please update your configuration so that the "known good" !!!
Tue Feb 23 15:45:41 2016 : Info: !!! clear text password is in Cleartext-Password, and not in User-Password. !!!
Tue Feb 23 15:45:41 2016 : Info: !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
Tue Feb 23 15:45:41 2016 : Info: # Executing group from file /etc/freeradius/sites-enabled/default
Tue Feb 23 15:45:41 2016 : Info: +- entering group authenticate {...}
Tue Feb 23 15:45:41 2016 : Info: [eap] EAP Identity
Tue Feb 23 15:45:41 2016 : Info: [eap] processing type md5
Tue Feb 23 15:45:41 2016 : Debug: rlm_eap_md5: Issuing Challenge
Tue Feb 23 15:45:41 2016 : Info: ++[eap] returns handled
Sending Access-Challenge of id 142 to 192.168.6.211 port 1812
Service-Type = Administrative-User
EAP-Message = 0x01010016041092556e11d1495a77ac213fbf04b83b8d
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x0d497f860d487b663cf1bfd5de864a48
Tue Feb 23 15:45:41 2016 : Info: Finished request 0.
Tue Feb 23 15:45:41 2016 : Debug: Going to the next request
Tue Feb 23 15:45:41 2016 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 192.168.6.211 port 1812, id=143, length=131
User-Name = "1234"
NAS-IP-Address = 211.6.168.192
NAS-Identifier = "SWITCH01-TEST"
NAS-Port-Type = Virtual
Service-Type = NAS-Prompt-User
State = 0x0d497f860d487b663cf1bfd5de864a48
EAP-Message = 0x020100060319
Message-Authenticator = 0xae7630668dd6118c160131b4cefec517
MS-RAS-Vendor = 184549376
Calling-Station-Id = "192.168.14.114"
Tue Feb 23 15:45:41 2016 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default
Tue Feb 23 15:45:41 2016 : Info: +- entering group authorize {...}
Tue Feb 23 15:45:41 2016 : Info: ++[preprocess] returns ok
Tue Feb 23 15:45:41 2016 : Info: ++[chap] returns noop
Tue Feb 23 15:45:41 2016 : Info: ++[mschap] returns noop
Tue Feb 23 15:45:41 2016 : Info: ++[digest] returns noop
Tue Feb 23 15:45:41 2016 : Info: [suffix] No '@' in User-Name = "1234", looking up realm NULL
Tue Feb 23 15:45:41 2016 : Info: [suffix] No such realm "NULL"
Tue Feb 23 15:45:41 2016 : Info: ++[suffix] returns noop
Tue Feb 23 15:45:41 2016 : Info: [eap] EAP packet type response id 1 length 6
Tue Feb 23 15:45:41 2016 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Tue Feb 23 15:45:41 2016 : Info: ++[eap] returns updated
Tue Feb 23 15:45:41 2016 : Info: [sql] expand: %{User-Name} -> 1234
Tue Feb 23 15:45:41 2016 : Info: [sql] sql_set_user escaped user --> '1234'
Tue Feb 23 15:45:41 2016 : Debug: rlm_sql (sql): Reserving sql socket id: 2
Tue Feb 23 15:45:41 2016 : Info: [sql] expand: SELECT id, username, attribute, value, op FROM radcheck WHERE username = '%{SQL-User-Name}' ORDER BY id -> SELECT id, username, attribute, value, op FROM radcheck WHERE username = '1234' ORDER BY id
Tue Feb 23 15:45:41 2016 : Debug: rlm_sql_mysql: query: SELECT id, username, attribute, value, op FROM radcheck WHERE username = '1234' ORDER BY id
Tue Feb 23 15:45:41 2016 : Info: [sql] User found in radcheck table
Tue Feb 23 15:45:41 2016 : Info: [sql] expand: SELECT id, username, attribute, value, op FROM radreply WHERE username = '%{SQL-User-Name}' ORDER BY id -> SELECT id, username, attribute, value, op FROM radreply WHERE username = '1234' ORDER BY id
Tue Feb 23 15:45:41 2016 : Debug: rlm_sql_mysql: query: SELECT id, username, attribute, value, op FROM radreply WHERE username = '1234' ORDER BY id
Tue Feb 23 15:45:41 2016 : Info: [sql] expand: SELECT groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority -> SELECT groupname FROM radusergroup WHERE username = '1234' ORDER BY priority
Tue Feb 23 15:45:41 2016 : Debug: rlm_sql_mysql: query: SELECT groupname FROM radusergroup WHERE username = '1234' ORDER BY priority
Tue Feb 23 15:45:41 2016 : Info: [sql] expand: SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = '%{Sql-Group}' ORDER BY id -> SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = 'HP-Procurve-Admin' ORDER BY id
Tue Feb 23 15:45:41 2016 : Debug: rlm_sql_mysql: query: SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = 'HP-Procurve-Admin' ORDER BY id
Tue Feb 23 15:45:41 2016 : Info: [sql] User found in group HP-Procurve-Admin
Tue Feb 23 15:45:41 2016 : Info: [sql] expand: SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = '%{Sql-Group}' ORDER BY id -> SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = 'HP-Procurve-Admin' ORDER BY id
Tue Feb 23 15:45:41 2016 : Debug: rlm_sql_mysql: query: SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = 'HP-Procurve-Admin' ORDER BY id
Tue Feb 23 15:45:41 2016 : Debug: rlm_sql (sql): Released sql socket id: 2
Tue Feb 23 15:45:41 2016 : Info: ++[sql] returns ok
Tue Feb 23 15:45:41 2016 : Info: ++[expiration] returns noop
Tue Feb 23 15:45:41 2016 : Info: ++[logintime] returns noop
Tue Feb 23 15:45:41 2016 : Info: [pap] WARNING: Auth-Type already set. Not setting to PAP
Tue Feb 23 15:45:41 2016 : Info: ++[pap] returns noop
Tue Feb 23 15:45:41 2016 : Info: Found Auth-Type = EAP
Tue Feb 23 15:45:41 2016 : Info: !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
Tue Feb 23 15:45:41 2016 : Info: !!! Replacing User-Password in config items with Cleartext-Password. !!!
Tue Feb 23 15:45:41 2016 : Info: !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
Tue Feb 23 15:45:41 2016 : Info: !!! Please update your configuration so that the "known good" !!!
Tue Feb 23 15:45:41 2016 : Info: !!! clear text password is in Cleartext-Password, and not in User-Password. !!!
Tue Feb 23 15:45:41 2016 : Info: !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
Tue Feb 23 15:45:41 2016 : Info: # Executing group from file /etc/freeradius/sites-enabled/default
Tue Feb 23 15:45:41 2016 : Info: +- entering group authenticate {...}
Tue Feb 23 15:45:41 2016 : Info: [eap] Request found, released from the list
Tue Feb 23 15:45:41 2016 : Info: [eap] EAP NAK
Tue Feb 23 15:45:41 2016 : Info: [eap] EAP-NAK asked for EAP-Type/peap
Tue Feb 23 15:45:41 2016 : Info: [eap] processing type tls
Tue Feb 23 15:45:41 2016 : Info: [tls] Initiate
Tue Feb 23 15:45:41 2016 : Info: [tls] Start returned 1
Tue Feb 23 15:45:41 2016 : Info: ++[eap] returns handled
Sending Access-Challenge of id 143 to 192.168.6.211 port 1812
Service-Type = Administrative-User
EAP-Message = 0x010200061920
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x0d497f860c4b66663cf1bfd5de864a48
Tue Feb 23 15:45:41 2016 : Info: Finished request 1.
Tue Feb 23 15:45:41 2016 : Debug: Going to the next request
Tue Feb 23 15:45:41 2016 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 192.168.6.211 port 1812, id=144, length=211
User-Name = "1234"
NAS-IP-Address = 211.6.168.192
NAS-Identifier = "SWITCH01-TEST"
NAS-Port-Type = Virtual
Service-Type = NAS-Prompt-User
State = 0x0d497f860c4b66663cf1bfd5de864a48
EAP-Message = 0x020200561900160303004b010000470303ab6769c0d58d7f9d9e64e9ab8b98b5fd91331b6289cea731d117c81ab3d7f2f900000c003d0035003c002f000a000901000012000d000e000c060105010401030102010101
Message-Authenticator = 0x3bd3a5d1bd573a86245aa80ae07478ff
MS-RAS-Vendor = 184549376
Calling-Station-Id = "192.168.14.114"
Tue Feb 23 15:45:41 2016 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default
Tue Feb 23 15:45:41 2016 : Info: +- entering group authorize {...}
Tue Feb 23 15:45:41 2016 : Info: ++[preprocess] returns ok
Tue Feb 23 15:45:41 2016 : Info: ++[chap] returns noop
Tue Feb 23 15:45:41 2016 : Info: ++[mschap] returns noop
Tue Feb 23 15:45:41 2016 : Info: ++[digest] returns noop
Tue Feb 23 15:45:41 2016 : Info: [suffix] No '@' in User-Name = "1234", looking up realm NULL
Tue Feb 23 15:45:41 2016 : Info: [suffix] No such realm "NULL"
Tue Feb 23 15:45:41 2016 : Info: ++[suffix] returns noop
Tue Feb 23 15:45:41 2016 : Info: [eap] EAP packet type response id 2 length 86
Tue Feb 23 15:45:41 2016 : Info: [eap] Continuing tunnel setup.
Tue Feb 23 15:45:41 2016 : Info: ++[eap] returns ok
Tue Feb 23 15:45:41 2016 : Info: Found Auth-Type = EAP
Tue Feb 23 15:45:41 2016 : Info: # Executing group from file /etc/freeradius/sites-enabled/default
Tue Feb 23 15:45:41 2016 : Info: +- entering group authenticate {...}
Tue Feb 23 15:45:41 2016 : Info: [eap] Request found, released from the list
Tue Feb 23 15:45:41 2016 : Info: [eap] EAP/peap
Tue Feb 23 15:45:41 2016 : Info: [eap] processing type peap
Tue Feb 23 15:45:41 2016 : Info: [peap] processing EAP-TLS
Tue Feb 23 15:45:41 2016 : Info: [peap] eaptls_verify returned 7
Tue Feb 23 15:45:41 2016 : Info: [peap] Done initial handshake
Tue Feb 23 15:45:41 2016 : Info: [peap] (other): before/accept initialization
Tue Feb 23 15:45:41 2016 : Info: [peap] TLS_accept: before/accept initialization
Tue Feb 23 15:45:41 2016 : Info: [peap] <<< TLS 1.0 Handshake [length 004b], ClientHello
Tue Feb 23 15:45:41 2016 : Info: [peap] TLS_accept: SSLv3 read client hello A
Tue Feb 23 15:45:41 2016 : Info: [peap] >>> TLS 1.0 Handshake [length 002a], ServerHello
Tue Feb 23 15:45:41 2016 : Info: [peap] TLS_accept: SSLv3 write server hello A
Tue Feb 23 15:45:41 2016 : Info: [peap] >>> TLS 1.0 Handshake [length 02e6], Certificate
Tue Feb 23 15:45:41 2016 : Info: [peap] TLS_accept: SSLv3 write certificate A
Tue Feb 23 15:45:41 2016 : Info: [peap] >>> TLS 1.0 Handshake [length 0004], ServerHelloDone
Tue Feb 23 15:45:41 2016 : Info: [peap] TLS_accept: SSLv3 write server done A
Tue Feb 23 15:45:41 2016 : Info: [peap] TLS_accept: SSLv3 flush data
Tue Feb 23 15:45:41 2016 : Info: [peap] TLS_accept: Need to read more data: SSLv3 read client certificate A
Tue Feb 23 15:45:41 2016 : Debug: In SSL Handshake Phase
Tue Feb 23 15:45:41 2016 : Debug: In SSL Accept mode
Tue Feb 23 15:45:41 2016 : Info: [peap] eaptls_process returned 13
Tue Feb 23 15:45:41 2016 : Info: [peap] EAPTLS_HANDLED
Tue Feb 23 15:45:41 2016 : Info: ++[eap] returns handled
Sending Access-Challenge of id 144 to 192.168.6.211 port 1812
EAP-Message = 0x010303291900160301002a02000026030134c2c8fe81a89853a504ac4216bfcd1fc0eda05b01ad8c4b3e03edff9e43127d0000350016030102e60b0002e20002df0002dc308202d8308201c0a003020102020900a0b10d9f121dd008300d06092a864886f70d01010b05003024312230200603550403131972616469757330322d6b657363682e636c617373656e2e6465301e170d3136303232323039333634395a170d3236303231393039333634395a3024312230200603550403131972616469757330322d6b657363682e636c617373656e2e646530820122300d06092a864886f70d01010105000382010f003082010a0282010100971a63c43d
EAP-Message = 0xf2b17bc57816c5c71129af0b0c5f5a204a9a95eaef60de83596dd0a29042c1a605502c5b95d73d9ca51609c2d41815e3c81a31dbd0ce43d20f9e206b1dd4dc2218b66d1a30d32a546d50ede101691f8df4d64ecd20896a1ca61163ef880b81d3243d647adb27bc943a379185208308203ee571f2d2d665e419e945e8d4bfe75b602b557222bbba56036f38cfc25f79e5cb03fc851cef447313c4474fa32dc4aa7bf3ed62eabcce51e15d5c575847982dc313f7e9621f0b4c7a6a33867bc0e396867f60977bf172e789850bf1b9a46a2594912b4f2b0eccfef51d2a87b2b3f534bf1485bf19c74dbbc1fea76340ab52c8cef84c19a7d1038d89f9c90203
EAP-Message = 0x010001a30d300b30090603551d1304023000300d06092a864886f70d01010b05000382010100218b7b3a3c12279ed2e0f5ff559a9ca32bb24f41262e22544b73dfc8876e0aff872161dd12f4855679b928fa34327111dc74c4cc45371f9661a23eaebea0824669534c78a630229e06c56a772ade4024d1042e4f3f96d1fa6d8055cc594e4f24b0517a5a554816ebfa557b5f5524695dbcdb92fe59323c0dcae23169a10e17964fdfc0d583537be90c080356747c652d2d44d77725fd36fced8cd5801cbf98a9cb7e25c1f332f303287a3e98c1cc67aefb8f02dc1e03c8b2555935b7cc389f50ee01f0f19a3211e35406654c242f3f3804b8f94776ef56
EAP-Message = 0x4f29c6c98be03ab4ca56f65f6c340b40867a94d719979692f3e5bfad7caec05cc561380b09056f7cdf16030100040e000000
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x0d497f860f4a66663cf1bfd5de864a48
Tue Feb 23 15:45:41 2016 : Info: Finished request 2.
Tue Feb 23 15:45:41 2016 : Debug: Going to the next request
Tue Feb 23 15:45:41 2016 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 192.168.6.211 port 1812, id=145, length=459
User-Name = "1234"
NAS-IP-Address = 211.6.168.192
NAS-Identifier = "SWITCH01-TEST"
NAS-Port-Type = Virtual
Service-Type = NAS-Prompt-User
State = 0x0d497f860f4a66663cf1bfd5de864a48
EAP-Message = 0x0203014c190016030101061000010201005dfdb2a2b54c590ef5d7cc360c6473c1486587d785b79ffead7bc460be2704428796e2b114874b8968c95ac964d71fcfe5d5ade81f82988dad45ca9b08c5205e269138b22ed0f6b339254f0fbf249b965f134aa59fbbeb310006de279dbea43115459743bb9d34520dae23c4db996e07cad77a149ad9da0e2b94a3effa431a113ddecddddba449674bb643465d7f6a32541a51d0560c24643f5d4953e8da3761c7d6555d45f789e8c2db692768f57ed65a395752e943fe7beb2a7c74b6b3ed661a2dfba98f899806a90a51a95ee14d11eb19014bc9a867d570b0e1dc29b2114864ffcc7e3a7e79ee4d6cfbd0
EAP-Message = 0x669aa7029cc07705cacc9d17cbf59a69fac73ac41403010001011603010030c7788739c5cc92d32780d2a3adddd296b748bdf783510c22ce44c3cb34d24aa031e9ed04ff61d09c0668d082dd4646e3
Message-Authenticator = 0x635e498c0eec7a5cccbe224717e8c348
MS-RAS-Vendor = 184549376
Calling-Station-Id = "192.168.14.114"
Tue Feb 23 15:45:42 2016 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default
Tue Feb 23 15:45:42 2016 : Info: +- entering group authorize {...}
Tue Feb 23 15:45:42 2016 : Info: ++[preprocess] returns ok
Tue Feb 23 15:45:42 2016 : Info: ++[chap] returns noop
Tue Feb 23 15:45:42 2016 : Info: ++[mschap] returns noop
Tue Feb 23 15:45:42 2016 : Info: ++[digest] returns noop
Tue Feb 23 15:45:42 2016 : Info: [suffix] No '@' in User-Name = "1234", looking up realm NULL
Tue Feb 23 15:45:42 2016 : Info: [suffix] No such realm "NULL"
Tue Feb 23 15:45:42 2016 : Info: ++[suffix] returns noop
Tue Feb 23 15:45:42 2016 : Info: [eap] EAP packet type response id 3 length 253
Tue Feb 23 15:45:42 2016 : Info: [eap] Continuing tunnel setup.
Tue Feb 23 15:45:42 2016 : Info: ++[eap] returns ok
Tue Feb 23 15:45:42 2016 : Info: Found Auth-Type = EAP
Tue Feb 23 15:45:42 2016 : Info: # Executing group from file /etc/freeradius/sites-enabled/default
Tue Feb 23 15:45:42 2016 : Info: +- entering group authenticate {...}
Tue Feb 23 15:45:42 2016 : Info: [eap] Request found, released from the list
Tue Feb 23 15:45:42 2016 : Info: [eap] EAP/peap
Tue Feb 23 15:45:42 2016 : Info: [eap] processing type peap
Tue Feb 23 15:45:42 2016 : Info: [peap] processing EAP-TLS
Tue Feb 23 15:45:42 2016 : Info: [peap] eaptls_verify returned 7
Tue Feb 23 15:45:42 2016 : Info: [peap] Done initial handshake
Tue Feb 23 15:45:42 2016 : Info: [peap] <<< TLS 1.0 Handshake [length 0106], ClientKeyExchange
Tue Feb 23 15:45:42 2016 : Info: [peap] TLS_accept: SSLv3 read client key exchange A
Tue Feb 23 15:45:42 2016 : Info: [peap] <<< TLS 1.0 ChangeCipherSpec [length 0001]
Tue Feb 23 15:45:42 2016 : Info: [peap] <<< TLS 1.0 Handshake [length 0010], Finished
Tue Feb 23 15:45:42 2016 : Info: [peap] TLS_accept: SSLv3 read finished A
Tue Feb 23 15:45:42 2016 : Info: [peap] >>> TLS 1.0 ChangeCipherSpec [length 0001]
Tue Feb 23 15:45:42 2016 : Info: [peap] TLS_accept: SSLv3 write change cipher spec A
Tue Feb 23 15:45:42 2016 : Info: [peap] >>> TLS 1.0 Handshake [length 0010], Finished
Tue Feb 23 15:45:42 2016 : Info: [peap] TLS_accept: SSLv3 write finished A
Tue Feb 23 15:45:42 2016 : Info: [peap] TLS_accept: SSLv3 flush data
Tue Feb 23 15:45:42 2016 : Info: [peap] (other): SSL negotiation finished successfully
Tue Feb 23 15:45:42 2016 : Debug: SSL Connection Established
Tue Feb 23 15:45:42 2016 : Info: [peap] eaptls_process returned 13
Tue Feb 23 15:45:42 2016 : Info: [peap] EAPTLS_HANDLED
Tue Feb 23 15:45:42 2016 : Info: ++[eap] returns handled
Sending Access-Challenge of id 145 to 192.168.6.211 port 1812
EAP-Message = 0x0104004119001403010001011603010030ea9ac534b5665ede970c0f2b17eeaef50b4889af5b2f1c0cb08c51c504fe230d42017d37df12ae7e23b8e38815a58993
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x0d497f860e4d66663cf1bfd5de864a48
Tue Feb 23 15:45:42 2016 : Info: Finished request 3.
Tue Feb 23 15:45:42 2016 : Debug: Going to the next request
Tue Feb 23 15:45:42 2016 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 192.168.6.211 port 1812, id=146, length=131
User-Name = "1234"
NAS-IP-Address = 211.6.168.192
NAS-Identifier = "SWITCH01-TEST"
NAS-Port-Type = Virtual
Service-Type = NAS-Prompt-User
State = 0x0d497f860e4d66663cf1bfd5de864a48
EAP-Message = 0x020400061900
Message-Authenticator = 0x70b79c3d9fa53cd08bb48bd815a0a2af
MS-RAS-Vendor = 184549376
Calling-Station-Id = "192.168.14.114"
Tue Feb 23 15:45:42 2016 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default
Tue Feb 23 15:45:42 2016 : Info: +- entering group authorize {...}
Tue Feb 23 15:45:42 2016 : Info: ++[preprocess] returns ok
Tue Feb 23 15:45:42 2016 : Info: ++[chap] returns noop
Tue Feb 23 15:45:42 2016 : Info: ++[mschap] returns noop
Tue Feb 23 15:45:42 2016 : Info: ++[digest] returns noop
Tue Feb 23 15:45:42 2016 : Info: [suffix] No '@' in User-Name = "1234", looking up realm NULL
Tue Feb 23 15:45:42 2016 : Info: [suffix] No such realm "NULL"
Tue Feb 23 15:45:42 2016 : Info: ++[suffix] returns noop
Tue Feb 23 15:45:42 2016 : Info: [eap] EAP packet type response id 4 length 6
Tue Feb 23 15:45:42 2016 : Info: [eap] Continuing tunnel setup.
Tue Feb 23 15:45:42 2016 : Info: ++[eap] returns ok
Tue Feb 23 15:45:42 2016 : Info: Found Auth-Type = EAP
Tue Feb 23 15:45:42 2016 : Info: # Executing group from file /etc/freeradius/sites-enabled/default
Tue Feb 23 15:45:42 2016 : Info: +- entering group authenticate {...}
Tue Feb 23 15:45:42 2016 : Info: [eap] Request found, released from the list
Tue Feb 23 15:45:42 2016 : Info: [eap] EAP/peap
Tue Feb 23 15:45:42 2016 : Info: [eap] processing type peap
Tue Feb 23 15:45:42 2016 : Info: [peap] processing EAP-TLS
Tue Feb 23 15:45:42 2016 : Info: [peap] Received TLS ACK
Tue Feb 23 15:45:42 2016 : Info: [peap] ACK handshake is finished
Tue Feb 23 15:45:42 2016 : Info: [peap] eaptls_verify returned 3
Tue Feb 23 15:45:42 2016 : Info: [peap] eaptls_process returned 3
Tue Feb 23 15:45:42 2016 : Info: [peap] EAPTLS_SUCCESS
Tue Feb 23 15:45:42 2016 : Info: [peap] Session established. Decoding tunneled attributes.
Tue Feb 23 15:45:42 2016 : Info: [peap] Peap state TUNNEL ESTABLISHED
Tue Feb 23 15:45:42 2016 : Info: ++[eap] returns handled
Sending Access-Challenge of id 146 to 192.168.6.211 port 1812
EAP-Message = 0x0105002b190017030100202b8a05992bfcee61c127eb4722aca63f80d3dfcc7bab78c60a3c41a659a10fb8
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x0d497f86094c66663cf1bfd5de864a48
Tue Feb 23 15:45:42 2016 : Info: Finished request 4.
Tue Feb 23 15:45:42 2016 : Debug: Going to the next request
Tue Feb 23 15:45:42 2016 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 192.168.6.211 port 1812, id=147, length=168
User-Name = "1234"
NAS-IP-Address = 211.6.168.192
NAS-Identifier = "SWITCH01-TEST"
NAS-Port-Type = Virtual
Service-Type = NAS-Prompt-User
State = 0x0d497f86094c66663cf1bfd5de864a48
EAP-Message = 0x0205002b1900170301002022f3c45761dfa101968af468f6a95339b01c176d48a72061254682aa6d1d7c5a
Message-Authenticator = 0x1a5d2573de10c5ea6a9d1f2aee5625fd
MS-RAS-Vendor = 184549376
Calling-Station-Id = "192.168.14.114"
Tue Feb 23 15:45:42 2016 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default
Tue Feb 23 15:45:42 2016 : Info: +- entering group authorize {...}
Tue Feb 23 15:45:42 2016 : Info: ++[preprocess] returns ok
Tue Feb 23 15:45:42 2016 : Info: ++[chap] returns noop
Tue Feb 23 15:45:42 2016 : Info: ++[mschap] returns noop
Tue Feb 23 15:45:42 2016 : Info: ++[digest] returns noop
Tue Feb 23 15:45:42 2016 : Info: [suffix] No '@' in User-Name = "1234", looking up realm NULL
Tue Feb 23 15:45:42 2016 : Info: [suffix] No such realm "NULL"
Tue Feb 23 15:45:42 2016 : Info: ++[suffix] returns noop
Tue Feb 23 15:45:42 2016 : Info: [eap] EAP packet type response id 5 length 43
Tue Feb 23 15:45:42 2016 : Info: [eap] Continuing tunnel setup.
Tue Feb 23 15:45:42 2016 : Info: ++[eap] returns ok
Tue Feb 23 15:45:42 2016 : Info: Found Auth-Type = EAP
Tue Feb 23 15:45:42 2016 : Info: # Executing group from file /etc/freeradius/sites-enabled/default
Tue Feb 23 15:45:42 2016 : Info: +- entering group authenticate {...}
Tue Feb 23 15:45:42 2016 : Info: [eap] Request found, released from the list
Tue Feb 23 15:45:42 2016 : Info: [eap] EAP/peap
Tue Feb 23 15:45:42 2016 : Info: [eap] processing type peap
Tue Feb 23 15:45:42 2016 : Info: [peap] processing EAP-TLS
Tue Feb 23 15:45:42 2016 : Info: [peap] eaptls_verify returned 7
Tue Feb 23 15:45:42 2016 : Info: [peap] Done initial handshake
Tue Feb 23 15:45:42 2016 : Info: [peap] eaptls_process returned 7
Tue Feb 23 15:45:42 2016 : Info: [peap] EAPTLS_OK
Tue Feb 23 15:45:42 2016 : Info: [peap] Session established. Decoding tunneled attributes.
Tue Feb 23 15:45:42 2016 : Info: [peap] Peap state WAITING FOR INNER IDENTITY
Tue Feb 23 15:45:42 2016 : Info: [peap] Identity - 1234
Tue Feb 23 15:45:42 2016 : Info: [peap] Got inner identity '1234'
Tue Feb 23 15:45:42 2016 : Info: [peap] Setting default EAP type for tunneled EAP session.
Tue Feb 23 15:45:42 2016 : Info: [peap] Got tunneled request
EAP-Message = 0x020500090131323334
server {
Tue Feb 23 15:45:42 2016 : Info: [peap] Setting User-Name to 1234
Sending tunneled request
EAP-Message = 0x020500090131323334
FreeRADIUS-Proxied-To = 127.0.0.1
User-Name = "1234"
server inner-tunnel {
Tue Feb 23 15:45:42 2016 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/inner-tunnel
Tue Feb 23 15:45:42 2016 : Info: +- entering group authorize {...}
Tue Feb 23 15:45:42 2016 : Info: ++[chap] returns noop
Tue Feb 23 15:45:42 2016 : Info: ++[mschap] returns noop
Tue Feb 23 15:45:42 2016 : Info: [suffix] No '@' in User-Name = "1234", looking up realm NULL
Tue Feb 23 15:45:42 2016 : Info: [suffix] No such realm "NULL"
Tue Feb 23 15:45:42 2016 : Info: ++[suffix] returns noop
Tue Feb 23 15:45:42 2016 : Info: ++[control] returns noop
Tue Feb 23 15:45:42 2016 : Info: [eap] EAP packet type response id 5 length 9
Tue Feb 23 15:45:42 2016 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Tue Feb 23 15:45:42 2016 : Info: ++[eap] returns updated
Tue Feb 23 15:45:42 2016 : Info: ++[files] returns noop
Tue Feb 23 15:45:42 2016 : Info: [sql] expand: %{User-Name} -> 1234
Tue Feb 23 15:45:42 2016 : Info: [sql] sql_set_user escaped user --> '1234'
Tue Feb 23 15:45:42 2016 : Debug: rlm_sql (sql): Reserving sql socket id: 1
Tue Feb 23 15:45:42 2016 : Info: [sql] expand: SELECT id, username, attribute, value, op FROM radcheck WHERE username = '%{SQL-User-Name}' ORDER BY id -> SELECT id, username, attribute, value, op FROM radcheck WHERE username = '1234' ORDER BY id
Tue Feb 23 15:45:42 2016 : Debug: rlm_sql_mysql: query: SELECT id, username, attribute, value, op FROM radcheck WHERE username = '1234' ORDER BY id
Tue Feb 23 15:45:42 2016 : Info: [sql] User found in radcheck table
Tue Feb 23 15:45:42 2016 : Info: [sql] expand: SELECT id, username, attribute, value, op FROM radreply WHERE username = '%{SQL-User-Name}' ORDER BY id -> SELECT id, username, attribute, value, op FROM radreply WHERE username = '1234' ORDER BY id
Tue Feb 23 15:45:42 2016 : Debug: rlm_sql_mysql: query: SELECT id, username, attribute, value, op FROM radreply WHERE username = '1234' ORDER BY id
Tue Feb 23 15:45:42 2016 : Info: [sql] expand: SELECT groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority -> SELECT groupname FROM radusergroup WHERE username = '1234' ORDER BY priority
Tue Feb 23 15:45:42 2016 : Debug: rlm_sql_mysql: query: SELECT groupname FROM radusergroup WHERE username = '1234' ORDER BY priority
Tue Feb 23 15:45:42 2016 : Info: [sql] expand: SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = '%{Sql-Group}' ORDER BY id -> SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = 'HP-Procurve-Admin' ORDER BY id
Tue Feb 23 15:45:42 2016 : Debug: rlm_sql_mysql: query: SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = 'HP-Procurve-Admin' ORDER BY id
Tue Feb 23 15:45:42 2016 : Debug: rlm_sql (sql): Released sql socket id: 1
Tue Feb 23 15:45:42 2016 : Info: ++[sql] returns ok
Tue Feb 23 15:45:42 2016 : Info: ++[expiration] returns noop
Tue Feb 23 15:45:42 2016 : Info: ++[logintime] returns noop
Tue Feb 23 15:45:42 2016 : Info: [pap] WARNING: Auth-Type already set. Not setting to PAP
Tue Feb 23 15:45:42 2016 : Info: ++[pap] returns noop
Tue Feb 23 15:45:42 2016 : Info: Found Auth-Type = EAP
Tue Feb 23 15:45:42 2016 : Info: !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
Tue Feb 23 15:45:42 2016 : Info: !!! Replacing User-Password in config items with Cleartext-Password. !!!
Tue Feb 23 15:45:42 2016 : Info: !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
Tue Feb 23 15:45:42 2016 : Info: !!! Please update your configuration so that the "known good" !!!
Tue Feb 23 15:45:42 2016 : Info: !!! clear text password is in Cleartext-Password, and not in User-Password. !!!
Tue Feb 23 15:45:42 2016 : Info: !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
Tue Feb 23 15:45:42 2016 : Info: # Executing group from file /etc/freeradius/sites-enabled/inner-tunnel
Tue Feb 23 15:45:42 2016 : Info: +- entering group authenticate {...}
Tue Feb 23 15:45:42 2016 : Info: [eap] EAP Identity
Tue Feb 23 15:45:42 2016 : Info: [eap] processing type mschapv2
Tue Feb 23 15:45:42 2016 : Debug: rlm_eap_mschapv2: Issuing Challenge
Tue Feb 23 15:45:42 2016 : Info: ++[eap] returns handled
} # server inner-tunnel
Tue Feb 23 15:45:42 2016 : Info: [peap] Got tunneled reply code 11
EAP-Message = 0x0106001e1a01060019108f9ae5e1e773168c098f021e5eb93d4831323334
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x6162be1b6164a4ac160d1d957d730383
Tue Feb 23 15:45:42 2016 : Info: [peap] Got tunneled reply RADIUS code 11
EAP-Message = 0x0106001e1a01060019108f9ae5e1e773168c098f021e5eb93d4831323334
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x6162be1b6164a4ac160d1d957d730383
Tue Feb 23 15:45:42 2016 : Info: [peap] Got tunneled Access-Challenge
PEAP tunnel data out 0000: 1a 01 06 00 19 10 8f 9a e5 e1 e7 73 16 8c 09 8f
PEAP tunnel data out 0010: 02 1e 5e b9 3d 48 31 32 33 34
Tue Feb 23 15:45:42 2016 : Info: ++[eap] returns handled
Sending Access-Challenge of id 147 to 192.168.6.211 port 1812
EAP-Message = 0x0106003b1900170301003067bf2338238b7bca8ef7ef4051623cf7eb1d140c350fc2cf1506a4f97d1e64494141be8566aaa6351f18cdcd51c2bad0
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x0d497f86084f66663cf1bfd5de864a48
Tue Feb 23 15:45:42 2016 : Info: Finished request 5.
Tue Feb 23 15:45:42 2016 : Debug: Going to the next request
Tue Feb 23 15:45:42 2016 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 192.168.6.211 port 1812, id=148, length=216
User-Name = "1234"
NAS-IP-Address = 211.6.168.192
NAS-Identifier = "SWITCH01-TEST"
NAS-Port-Type = Virtual
Service-Type = NAS-Prompt-User
State = 0x0d497f86084f66663cf1bfd5de864a48
EAP-Message = 0x0206005b19001703010050c54c0374d48331d44c233ddf239ed06afcdf5825bb291bb909009b9d0381bbb4c1caa824a57ed00f1764b4ce50d13cb6299d20f22d24ec58d9d53fad9462b355ae34b84835129fcfb2093a461d567048
Message-Authenticator = 0xd7fb5217628dd8369628f52948d02c67
MS-RAS-Vendor = 184549376
Calling-Station-Id = "192.168.14.114"
Tue Feb 23 15:45:42 2016 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default
Tue Feb 23 15:45:42 2016 : Info: +- entering group authorize {...}
Tue Feb 23 15:45:42 2016 : Info: ++[preprocess] returns ok
Tue Feb 23 15:45:42 2016 : Info: ++[chap] returns noop
Tue Feb 23 15:45:42 2016 : Info: ++[mschap] returns noop
Tue Feb 23 15:45:42 2016 : Info: ++[digest] returns noop
Tue Feb 23 15:45:42 2016 : Info: [suffix] No '@' in User-Name = "1234", looking up realm NULL
Tue Feb 23 15:45:42 2016 : Info: [suffix] No such realm "NULL"
Tue Feb 23 15:45:42 2016 : Info: ++[suffix] returns noop
Tue Feb 23 15:45:42 2016 : Info: [eap] EAP packet type response id 6 length 91
Tue Feb 23 15:45:42 2016 : Info: [eap] Continuing tunnel setup.
Tue Feb 23 15:45:42 2016 : Info: ++[eap] returns ok
Tue Feb 23 15:45:42 2016 : Info: Found Auth-Type = EAP
Tue Feb 23 15:45:42 2016 : Info: # Executing group from file /etc/freeradius/sites-enabled/default
Tue Feb 23 15:45:42 2016 : Info: +- entering group authenticate {...}
Tue Feb 23 15:45:42 2016 : Info: [eap] Request found, released from the list
Tue Feb 23 15:45:42 2016 : Info: [eap] EAP/peap
Tue Feb 23 15:45:42 2016 : Info: [eap] processing type peap
Tue Feb 23 15:45:42 2016 : Info: [peap] processing EAP-TLS
Tue Feb 23 15:45:42 2016 : Info: [peap] eaptls_verify returned 7
Tue Feb 23 15:45:42 2016 : Info: [peap] Done initial handshake
Tue Feb 23 15:45:42 2016 : Info: [peap] eaptls_process returned 7
Tue Feb 23 15:45:42 2016 : Info: [peap] EAPTLS_OK
Tue Feb 23 15:45:42 2016 : Info: [peap] Session established. Decoding tunneled attributes.
Tue Feb 23 15:45:42 2016 : Info: [peap] Peap state phase2
Tue Feb 23 15:45:42 2016 : Info: [peap] EAP type mschapv2
Tue Feb 23 15:45:42 2016 : Info: [peap] Got tunneled request
EAP-Message = 0x0206003f1a0206003a31da54aae7ed025f63818a1f7b17cd934800000000000000006941aa38ea42622be320ddeca697b590fef937d30cd993760031323334
server {
Tue Feb 23 15:45:42 2016 : Info: [peap] Setting User-Name to 1234
Sending tunneled request
EAP-Message = 0x0206003f1a0206003a31da54aae7ed025f63818a1f7b17cd934800000000000000006941aa38ea42622be320ddeca697b590fef937d30cd993760031323334
FreeRADIUS-Proxied-To = 127.0.0.1
User-Name = "1234"
State = 0x6162be1b6164a4ac160d1d957d730383
server inner-tunnel {
Tue Feb 23 15:45:42 2016 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/inner-tunnel
Tue Feb 23 15:45:42 2016 : Info: +- entering group authorize {...}
Tue Feb 23 15:45:42 2016 : Info: ++[chap] returns noop
Tue Feb 23 15:45:42 2016 : Info: ++[mschap] returns noop
Tue Feb 23 15:45:42 2016 : Info: [suffix] No '@' in User-Name = "1234", looking up realm NULL
Tue Feb 23 15:45:42 2016 : Info: [suffix] No such realm "NULL"
Tue Feb 23 15:45:42 2016 : Info: ++[suffix] returns noop
Tue Feb 23 15:45:42 2016 : Info: ++[control] returns noop
Tue Feb 23 15:45:42 2016 : Info: [eap] EAP packet type response id 6 length 63
Tue Feb 23 15:45:42 2016 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Tue Feb 23 15:45:42 2016 : Info: ++[eap] returns updated
Tue Feb 23 15:45:42 2016 : Info: ++[files] returns noop
Tue Feb 23 15:45:42 2016 : Info: [sql] expand: %{User-Name} -> 1234
Tue Feb 23 15:45:42 2016 : Info: [sql] sql_set_user escaped user --> '1234'
Tue Feb 23 15:45:42 2016 : Debug: rlm_sql (sql): Reserving sql socket id: 0
Tue Feb 23 15:45:42 2016 : Info: [sql] expand: SELECT id, username, attribute, value, op FROM radcheck WHERE username = '%{SQL-User-Name}' ORDER BY id -> SELECT id, username, attribute, value, op FROM radcheck WHERE username = '1234' ORDER BY id
Tue Feb 23 15:45:42 2016 : Debug: rlm_sql_mysql: query: SELECT id, username, attribute, value, op FROM radcheck WHERE username = '1234' ORDER BY id
Tue Feb 23 15:45:42 2016 : Info: [sql] User found in radcheck table
Tue Feb 23 15:45:42 2016 : Info: [sql] expand: SELECT id, username, attribute, value, op FROM radreply WHERE username = '%{SQL-User-Name}' ORDER BY id -> SELECT id, username, attribute, value, op FROM radreply WHERE username = '1234' ORDER BY id
Tue Feb 23 15:45:42 2016 : Debug: rlm_sql_mysql: query: SELECT id, username, attribute, value, op FROM radreply WHERE username = '1234' ORDER BY id
Tue Feb 23 15:45:42 2016 : Info: [sql] expand: SELECT groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority -> SELECT groupname FROM radusergroup WHERE username = '1234' ORDER BY priority
Tue Feb 23 15:45:42 2016 : Debug: rlm_sql_mysql: query: SELECT groupname FROM radusergroup WHERE username = '1234' ORDER BY priority
Tue Feb 23 15:45:42 2016 : Info: [sql] expand: SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = '%{Sql-Group}' ORDER BY id -> SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = 'HP-Procurve-Admin' ORDER BY id
Tue Feb 23 15:45:42 2016 : Debug: rlm_sql_mysql: query: SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = 'HP-Procurve-Admin' ORDER BY id
Tue Feb 23 15:45:42 2016 : Debug: rlm_sql (sql): Released sql socket id: 0
Tue Feb 23 15:45:42 2016 : Info: ++[sql] returns ok
Tue Feb 23 15:45:42 2016 : Info: ++[expiration] returns noop
Tue Feb 23 15:45:42 2016 : Info: ++[logintime] returns noop
Tue Feb 23 15:45:42 2016 : Info: [pap] WARNING: Auth-Type already set. Not setting to PAP
Tue Feb 23 15:45:42 2016 : Info: ++[pap] returns noop
Tue Feb 23 15:45:42 2016 : Info: Found Auth-Type = EAP
Tue Feb 23 15:45:42 2016 : Info: !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
Tue Feb 23 15:45:42 2016 : Info: !!! Replacing User-Password in config items with Cleartext-Password. !!!
Tue Feb 23 15:45:42 2016 : Info: !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
Tue Feb 23 15:45:42 2016 : Info: !!! Please update your configuration so that the "known good" !!!
Tue Feb 23 15:45:42 2016 : Info: !!! clear text password is in Cleartext-Password, and not in User-Password. !!!
Tue Feb 23 15:45:42 2016 : Info: !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
Tue Feb 23 15:45:42 2016 : Info: # Executing group from file /etc/freeradius/sites-enabled/inner-tunnel
Tue Feb 23 15:45:42 2016 : Info: +- entering group authenticate {...}
Tue Feb 23 15:45:42 2016 : Info: [eap] Request found, released from the list
Tue Feb 23 15:45:42 2016 : Info: [eap] EAP/mschapv2
Tue Feb 23 15:45:42 2016 : Info: [eap] processing type mschapv2
Tue Feb 23 15:45:42 2016 : Info: [mschapv2] # Executing group from file /etc/freeradius/sites-enabled/inner-tunnel
Tue Feb 23 15:45:42 2016 : Info: [mschapv2] +- entering group MS-CHAP {...}
Tue Feb 23 15:45:42 2016 : Info: [mschap] Creating challenge hash with username: 1234
Tue Feb 23 15:45:42 2016 : Info: [mschap] Told to do MS-CHAPv2 for 1234 with NT-Password
Tue Feb 23 15:45:42 2016 : Info: [mschap] adding MS-CHAPv2 MPPE keys
Tue Feb 23 15:45:42 2016 : Info: ++[mschap] returns ok
Tue Feb 23 15:45:42 2016 : Debug: MSCHAP Success
Tue Feb 23 15:45:42 2016 : Info: ++[eap] returns handled
} # server inner-tunnel
Tue Feb 23 15:45:42 2016 : Info: [peap] Got tunneled reply code 11
EAP-Message = 0x010700331a0306002e533d31453141333445313845333144453634323243303744374444463833423436314635434132424136
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x6162be1b6065a4ac160d1d957d730383
Tue Feb 23 15:45:42 2016 : Info: [peap] Got tunneled reply RADIUS code 11
EAP-Message = 0x010700331a0306002e533d31453141333445313845333144453634323243303744374444463833423436314635434132424136
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x6162be1b6065a4ac160d1d957d730383
Tue Feb 23 15:45:42 2016 : Info: [peap] Got tunneled Access-Challenge
PEAP tunnel data out 0000: 1a 03 06 00 2e 53 3d 31 45 31 41 33 34 45 31 38
PEAP tunnel data out 0010: 45 33 31 44 45 36 34 32 32 43 30 37 44 37 44 44
PEAP tunnel data out 0020: 46 38 33 42 34 36 31 46 35 43 41 32 42 41 36
Tue Feb 23 15:45:42 2016 : Info: ++[eap] returns handled
Sending Access-Challenge of id 148 to 192.168.6.211 port 1812
EAP-Message = 0x0107005b19001703010050c4d6781c42a769e49995eddde0f39054a452a415ba7033be63f401fa2c876c2fed4d926e97a11a7c5ca625adfd746efcb3e0736f62c967ba51ee0718385ee5daaa58ac9529d80821fdc70c1efa6154c0
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x0d497f860b4e66663cf1bfd5de864a48
Tue Feb 23 15:45:42 2016 : Info: Finished request 6.
Tue Feb 23 15:45:42 2016 : Debug: Going to the next request
Tue Feb 23 15:45:42 2016 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 192.168.6.211 port 1812, id=149, length=168
User-Name = "1234"
NAS-IP-Address = 211.6.168.192
NAS-Identifier = "SWITCH01-TEST"
NAS-Port-Type = Virtual
Service-Type = NAS-Prompt-User
State = 0x0d497f860b4e66663cf1bfd5de864a48
EAP-Message = 0x0207002b190017030100203bd61645e3583319a411219921d8df3471af6a1012bf51c9f59dbac842803fe4
Message-Authenticator = 0x1428e10214392763b0e798d4ce4b9738
MS-RAS-Vendor = 184549376
Calling-Station-Id = "192.168.14.114"
Tue Feb 23 15:45:42 2016 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default
Tue Feb 23 15:45:42 2016 : Info: +- entering group authorize {...}
Tue Feb 23 15:45:42 2016 : Info: ++[preprocess] returns ok
Tue Feb 23 15:45:42 2016 : Info: ++[chap] returns noop
Tue Feb 23 15:45:42 2016 : Info: ++[mschap] returns noop
Tue Feb 23 15:45:42 2016 : Info: ++[digest] returns noop
Tue Feb 23 15:45:42 2016 : Info: [suffix] No '@' in User-Name = "1234", looking up realm NULL
Tue Feb 23 15:45:42 2016 : Info: [suffix] No such realm "NULL"
Tue Feb 23 15:45:42 2016 : Info: ++[suffix] returns noop
Tue Feb 23 15:45:42 2016 : Info: [eap] EAP packet type response id 7 length 43
Tue Feb 23 15:45:42 2016 : Info: [eap] Continuing tunnel setup.
Tue Feb 23 15:45:42 2016 : Info: ++[eap] returns ok
Tue Feb 23 15:45:42 2016 : Info: Found Auth-Type = EAP
Tue Feb 23 15:45:42 2016 : Info: # Executing group from file /etc/freeradius/sites-enabled/default
Tue Feb 23 15:45:42 2016 : Info: +- entering group authenticate {...}
Tue Feb 23 15:45:42 2016 : Info: [eap] Request found, released from the list
Tue Feb 23 15:45:42 2016 : Info: [eap] EAP/peap
Tue Feb 23 15:45:42 2016 : Info: [eap] processing type peap
Tue Feb 23 15:45:42 2016 : Info: [peap] processing EAP-TLS
Tue Feb 23 15:45:42 2016 : Info: [peap] eaptls_verify returned 7
Tue Feb 23 15:45:42 2016 : Info: [peap] Done initial handshake
Tue Feb 23 15:45:42 2016 : Info: [peap] eaptls_process returned 7
Tue Feb 23 15:45:42 2016 : Info: [peap] EAPTLS_OK
Tue Feb 23 15:45:42 2016 : Info: [peap] Session established. Decoding tunneled attributes.
Tue Feb 23 15:45:42 2016 : Info: [peap] Peap state phase2
Tue Feb 23 15:45:42 2016 : Info: [peap] EAP type mschapv2
Tue Feb 23 15:45:42 2016 : Info: [peap] Got tunneled request
EAP-Message = 0x020700061a03
server {
Tue Feb 23 15:45:42 2016 : Info: [peap] Setting User-Name to 1234
Sending tunneled request
EAP-Message = 0x020700061a03
FreeRADIUS-Proxied-To = 127.0.0.1
User-Name = "1234"
State = 0x6162be1b6065a4ac160d1d957d730383
server inner-tunnel {
Tue Feb 23 15:45:42 2016 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/inner-tunnel
Tue Feb 23 15:45:42 2016 : Info: +- entering group authorize {...}
Tue Feb 23 15:45:42 2016 : Info: ++[chap] returns noop
Tue Feb 23 15:45:42 2016 : Info: ++[mschap] returns noop
Tue Feb 23 15:45:42 2016 : Info: [suffix] No '@' in User-Name = "1234", looking up realm NULL
Tue Feb 23 15:45:42 2016 : Info: [suffix] No such realm "NULL"
Tue Feb 23 15:45:42 2016 : Info: ++[suffix] returns noop
Tue Feb 23 15:45:42 2016 : Info: ++[control] returns noop
Tue Feb 23 15:45:42 2016 : Info: [eap] EAP packet type response id 7 length 6
Tue Feb 23 15:45:42 2016 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Tue Feb 23 15:45:42 2016 : Info: ++[eap] returns updated
Tue Feb 23 15:45:42 2016 : Info: ++[files] returns noop
Tue Feb 23 15:45:42 2016 : Info: [sql] expand: %{User-Name} -> 1234
Tue Feb 23 15:45:42 2016 : Info: [sql] sql_set_user escaped user --> '1234'
Tue Feb 23 15:45:42 2016 : Debug: rlm_sql (sql): Reserving sql socket id: 4
Tue Feb 23 15:45:42 2016 : Info: [sql] expand: SELECT id, username, attribute, value, op FROM radcheck WHERE username = '%{SQL-User-Name}' ORDER BY id -> SELECT id, username, attribute, value, op FROM radcheck WHERE username = '1234' ORDER BY id
Tue Feb 23 15:45:42 2016 : Debug: rlm_sql_mysql: query: SELECT id, username, attribute, value, op FROM radcheck WHERE username = '1234' ORDER BY id
Tue Feb 23 15:45:42 2016 : Info: [sql] User found in radcheck table
Tue Feb 23 15:45:42 2016 : Info: [sql] expand: SELECT id, username, attribute, value, op FROM radreply WHERE username = '%{SQL-User-Name}' ORDER BY id -> SELECT id, username, attribute, value, op FROM radreply WHERE username = '1234' ORDER BY id
Tue Feb 23 15:45:42 2016 : Debug: rlm_sql_mysql: query: SELECT id, username, attribute, value, op FROM radreply WHERE username = '1234' ORDER BY id
Tue Feb 23 15:45:42 2016 : Info: [sql] expand: SELECT groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority -> SELECT groupname FROM radusergroup WHERE username = '1234' ORDER BY priority
Tue Feb 23 15:45:42 2016 : Debug: rlm_sql_mysql: query: SELECT groupname FROM radusergroup WHERE username = '1234' ORDER BY priority
Tue Feb 23 15:45:42 2016 : Info: [sql] expand: SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = '%{Sql-Group}' ORDER BY id -> SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = 'HP-Procurve-Admin' ORDER BY id
Tue Feb 23 15:45:42 2016 : Debug: rlm_sql_mysql: query: SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = 'HP-Procurve-Admin' ORDER BY id
Tue Feb 23 15:45:42 2016 : Debug: rlm_sql (sql): Released sql socket id: 4
Tue Feb 23 15:45:42 2016 : Info: ++[sql] returns ok
Tue Feb 23 15:45:42 2016 : Info: ++[expiration] returns noop
Tue Feb 23 15:45:42 2016 : Info: ++[logintime] returns noop
Tue Feb 23 15:45:42 2016 : Info: [pap] WARNING: Auth-Type already set. Not setting to PAP
Tue Feb 23 15:45:42 2016 : Info: ++[pap] returns noop
Tue Feb 23 15:45:42 2016 : Info: Found Auth-Type = EAP
Tue Feb 23 15:45:42 2016 : Info: !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
Tue Feb 23 15:45:42 2016 : Info: !!! Replacing User-Password in config items with Cleartext-Password. !!!
Tue Feb 23 15:45:42 2016 : Info: !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
Tue Feb 23 15:45:42 2016 : Info: !!! Please update your configuration so that the "known good" !!!
Tue Feb 23 15:45:42 2016 : Info: !!! clear text password is in Cleartext-Password, and not in User-Password. !!!
Tue Feb 23 15:45:42 2016 : Info: !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
Tue Feb 23 15:45:42 2016 : Info: # Executing group from file /etc/freeradius/sites-enabled/inner-tunnel
Tue Feb 23 15:45:42 2016 : Info: +- entering group authenticate {...}
Tue Feb 23 15:45:42 2016 : Info: [eap] Request found, released from the list
Tue Feb 23 15:45:42 2016 : Info: [eap] EAP/mschapv2
Tue Feb 23 15:45:42 2016 : Info: [eap] processing type mschapv2
Tue Feb 23 15:45:42 2016 : Info: [eap] Freeing handler
Tue Feb 23 15:45:42 2016 : Info: ++[eap] returns ok
Tue Feb 23 15:45:42 2016 : Info: # Executing section post-auth from file /etc/freeradius/sites-enabled/inner-tunnel
Tue Feb 23 15:45:42 2016 : Info: +- entering group post-auth {...}
Tue Feb 23 15:45:42 2016 : Info: [sql] expand: %{User-Name} -> 1234
Tue Feb 23 15:45:42 2016 : Info: [sql] sql_set_user escaped user --> '1234'
Tue Feb 23 15:45:42 2016 : Info: [sql] expand: %{User-Password} ->
Tue Feb 23 15:45:42 2016 : Info: [sql] ... expanding second conditional
Tue Feb 23 15:45:42 2016 : Info: [sql] expand: %{Chap-Password} ->
Tue Feb 23 15:45:42 2016 : Info: [sql] expand: INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '%{User-Name}', '%{%{User-Password}:-%{Chap-Password}}', '%{reply:Packet-Type}', '%S') -> INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '1234', '', 'Access-Accept', '2016-02-23 15:45:42')
Tue Feb 23 15:45:42 2016 : Info: [sql] expand: /var/log/freeradius/sqltrace.sql -> /var/log/freeradius/sqltrace.sql
Tue Feb 23 15:45:42 2016 : Debug: rlm_sql (sql) in sql_postauth: query is INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '1234', '', 'Access-Accept', '2016-02-23 15:45:42')
Tue Feb 23 15:45:42 2016 : Debug: rlm_sql (sql): Reserving sql socket id: 3
Tue Feb 23 15:45:42 2016 : Debug: rlm_sql_mysql: query: INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '1234', '', 'Access-Accept', '2016-02-23 15:45:42')
Tue Feb 23 15:45:42 2016 : Debug: rlm_sql (sql): Released sql socket id: 3
Tue Feb 23 15:45:42 2016 : Info: ++[sql] returns ok
Tue Feb 23 15:45:42 2016 : Info: expand: %{request:User-Name} -> 1234
Tue Feb 23 15:45:42 2016 : Info: ++[outer.reply] returns ok
} # server inner-tunnel
Tue Feb 23 15:45:42 2016 : Info: [peap] Got tunneled reply code 2
MS-MPPE-Encryption-Policy = 0x00000002
MS-MPPE-Encryption-Types = 0x00000004
MS-MPPE-Send-Key = 0x912567151985026409e260663b70aa06
MS-MPPE-Recv-Key = 0x02a930052a14bd9b484e190eaabd4b49
EAP-Message = 0x03070004
Message-Authenticator = 0x00000000000000000000000000000000
User-Name = "1234"
Tue Feb 23 15:45:42 2016 : Info: [peap] Got tunneled reply RADIUS code 2
MS-MPPE-Encryption-Policy = 0x00000002
MS-MPPE-Encryption-Types = 0x00000004
MS-MPPE-Send-Key = 0x912567151985026409e260663b70aa06
MS-MPPE-Recv-Key = 0x02a930052a14bd9b484e190eaabd4b49
EAP-Message = 0x03070004
Message-Authenticator = 0x00000000000000000000000000000000
User-Name = "1234"
Tue Feb 23 15:45:42 2016 : Info: [peap] Tunneled authentication was successful.
Tue Feb 23 15:45:42 2016 : Info: [peap] SUCCESS
Tue Feb 23 15:45:42 2016 : Info: [peap] Saving tunneled attributes for later
Tue Feb 23 15:45:42 2016 : Info: ++[eap] returns handled
Sending Access-Challenge of id 149 to 192.168.6.211 port 1812
User-Name = "1234"
Service-Type = Administrative-User
EAP-Message = 0x0108002b190017030100202db20bbce3b72afa194b4f3d3bc314eaa7406a57c511ba71b42d2ffce72d01fc
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x0d497f860a4166663cf1bfd5de864a48
Tue Feb 23 15:45:42 2016 : Info: Finished request 7.
Tue Feb 23 15:45:42 2016 : Debug: Going to the next request
Tue Feb 23 15:45:42 2016 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 192.168.6.211 port 1812, id=150, length=168
User-Name = "1234"
NAS-IP-Address = 211.6.168.192
NAS-Identifier = "SWITCH01-TEST"
NAS-Port-Type = Virtual
Service-Type = NAS-Prompt-User
State = 0x0d497f860a4166663cf1bfd5de864a48
EAP-Message = 0x0208002b19001703010020358541ebeef1d422e9a8abf682c3ff01eccba593fee137a12c3d3fe651a8c471
Message-Authenticator = 0xd046b2197cd82e8855887dbd74e9edd3
MS-RAS-Vendor = 184549376
Calling-Station-Id = "192.168.14.114"
Tue Feb 23 15:45:42 2016 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default
Tue Feb 23 15:45:42 2016 : Info: +- entering group authorize {...}
Tue Feb 23 15:45:42 2016 : Info: ++[preprocess] returns ok
Tue Feb 23 15:45:42 2016 : Info: ++[chap] returns noop
Tue Feb 23 15:45:42 2016 : Info: ++[mschap] returns noop
Tue Feb 23 15:45:42 2016 : Info: ++[digest] returns noop
Tue Feb 23 15:45:42 2016 : Info: [suffix] No '@' in User-Name = "1234", looking up realm NULL
Tue Feb 23 15:45:42 2016 : Info: [suffix] No such realm "NULL"
Tue Feb 23 15:45:42 2016 : Info: ++[suffix] returns noop
Tue Feb 23 15:45:42 2016 : Info: [eap] EAP packet type response id 8 length 43
Tue Feb 23 15:45:42 2016 : Info: [eap] Continuing tunnel setup.
Tue Feb 23 15:45:42 2016 : Info: ++[eap] returns ok
Tue Feb 23 15:45:42 2016 : Info: Found Auth-Type = EAP
Tue Feb 23 15:45:42 2016 : Info: # Executing group from file /etc/freeradius/sites-enabled/default
Tue Feb 23 15:45:42 2016 : Info: +- entering group authenticate {...}
Tue Feb 23 15:45:42 2016 : Info: [eap] Request found, released from the list
Tue Feb 23 15:45:42 2016 : Info: [eap] EAP/peap
Tue Feb 23 15:45:42 2016 : Info: [eap] processing type peap
Tue Feb 23 15:45:42 2016 : Info: [peap] processing EAP-TLS
Tue Feb 23 15:45:42 2016 : Info: [peap] eaptls_verify returned 7
Tue Feb 23 15:45:42 2016 : Info: [peap] Done initial handshake
Tue Feb 23 15:45:42 2016 : Info: [peap] eaptls_process returned 7
Tue Feb 23 15:45:42 2016 : Info: [peap] EAPTLS_OK
Tue Feb 23 15:45:42 2016 : Info: [peap] Session established. Decoding tunneled attributes.
Tue Feb 23 15:45:42 2016 : Info: [peap] Peap state send tlv success
Tue Feb 23 15:45:42 2016 : Info: [peap] Received EAP-TLV response.
Tue Feb 23 15:45:42 2016 : Info: [peap] Success
Tue Feb 23 15:45:42 2016 : Info: [peap] Using saved attributes from the original Access-Accept
User-Name = "1234"
Tue Feb 23 15:45:42 2016 : Info: [eap] Freeing handler
Tue Feb 23 15:45:42 2016 : Info: ++[eap] returns ok
Tue Feb 23 15:45:42 2016 : Info: # Executing section post-auth from file /etc/freeradius/sites-enabled/default
Tue Feb 23 15:45:42 2016 : Info: +- entering group post-auth {...}
Tue Feb 23 15:45:42 2016 : Info: [sql] expand: %{User-Name} -> 1234
Tue Feb 23 15:45:42 2016 : Info: [sql] sql_set_user escaped user --> '1234'
Tue Feb 23 15:45:42 2016 : Info: [sql] expand: %{User-Password} ->
Tue Feb 23 15:45:42 2016 : Info: [sql] ... expanding second conditional
Tue Feb 23 15:45:42 2016 : Info: [sql] expand: %{Chap-Password} ->
Tue Feb 23 15:45:42 2016 : Info: [sql] expand: INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '%{User-Name}', '%{%{User-Password}:-%{Chap-Password}}', '%{reply:Packet-Type}', '%S') -> INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '1234', '', 'Access-Accept', '2016-02-23 15:45:42')
Tue Feb 23 15:45:42 2016 : Info: [sql] expand: /var/log/freeradius/sqltrace.sql -> /var/log/freeradius/sqltrace.sql
Tue Feb 23 15:45:42 2016 : Debug: rlm_sql (sql) in sql_postauth: query is INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '1234', '', 'Access-Accept', '2016-02-23 15:45:42')
Tue Feb 23 15:45:42 2016 : Debug: rlm_sql (sql): Reserving sql socket id: 2
Tue Feb 23 15:45:42 2016 : Debug: rlm_sql_mysql: query: INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '1234', '', 'Access-Accept', '2016-02-23 15:45:42')
Tue Feb 23 15:45:42 2016 : Debug: rlm_sql (sql): Released sql socket id: 2
Tue Feb 23 15:45:42 2016 : Info: ++[sql] returns ok
Tue Feb 23 15:45:42 2016 : Info: ++[exec] returns noop
Sending Access-Accept of id 150 to 192.168.6.211 port 1812
User-Name = "1234"
MS-MPPE-Recv-Key = 0xb59a7655a33a5a5b6979a195b6277d8e7ac7a128b3eb78f2a941de634490be80
MS-MPPE-Send-Key = 0x47a29459f2ffd034955b9c980be7b66750706df94a0f24f279ca9999b3753da6
EAP-Message = 0x03080004
Message-Authenticator = 0x00000000000000000000000000000000
Tue Feb 23 15:45:42 2016 : Info: Finished request 8.
Tue Feb 23 15:45:42 2016 : Debug: Going to the next request
Tue Feb 23 15:45:42 2016 : Debug: Waking up in 4.9 seconds.
Tue Feb 23 15:45:46 2016 : Info: Cleaning up request 0 ID 142 with timestamp +8
Tue Feb 23 15:45:46 2016 : Info: Cleaning up request 1 ID 143 with timestamp +8
Tue Feb 23 15:45:46 2016 : Info: Cleaning up request 2 ID 144 with timestamp +8
Tue Feb 23 15:45:47 2016 : Info: Cleaning up request 3 ID 145 with timestamp +9
Tue Feb 23 15:45:47 2016 : Info: Cleaning up request 4 ID 146 with timestamp +9
Tue Feb 23 15:45:47 2016 : Info: Cleaning up request 5 ID 147 with timestamp +9
Tue Feb 23 15:45:47 2016 : Info: Cleaning up request 6 ID 148 with timestamp +9
Tue Feb 23 15:45:47 2016 : Info: Cleaning up request 7 ID 149 with timestamp +9
Tue Feb 23 15:45:47 2016 : Info: Cleaning up request 8 ID 150 with timestamp +9
Tue Feb 23 15:45:47 2016 : Info: Ready to process requests.
Best regards
Jonas
More information about the Freeradius-Users
mailing list