Re: Calling eap_md5 to process EAP data in inner-tunnel

8 Oct 2014


      On 10/08/2014 01:00 PM, Alan Buxey wrote:
...
That's not the full output of radiusd -X :(
alan
sorry, really full radiusd -X

radiusd: FreeRADIUS Version 3.0.4, for host x86_64-unknown-linux-gnu, 
built on Oct  3 2014 at 12:41:51
Copyright (C) 1999-2014 The FreeRADIUS server project and contributors
There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A
PARTICULAR PURPOSE
You may redistribute copies of FreeRADIUS under the terms of the
GNU General Public License
For more information about these matters, see the file named COPYRIGHT
Starting - reading configuration files ...
including dictionary file /usr/local/share/freeradius/dictionary
including dictionary file /usr/local/share/freeradius/dictionary.dhcp
including dictionary file /usr/local/share/freeradius/dictionary.vqp
including dictionary file /etc/raddb/dictionary
including configuration file /etc/raddb/radiusd.conf
including configuration file /etc/raddb/proxy.conf
including configuration file /etc/raddb/clients.conf
including files in directory /etc/raddb/mods-enabled/
including configuration file /etc/raddb/mods-enabled/always
including configuration file /etc/raddb/mods-enabled/attr_filter
including configuration file /etc/raddb/mods-enabled/cache_eap
including configuration file /etc/raddb/mods-enabled/chap
including configuration file /etc/raddb/mods-enabled/detail
including configuration file /etc/raddb/mods-enabled/detail.log
including configuration file /etc/raddb/mods-enabled/digest
including configuration file /etc/raddb/mods-enabled/dhcp
including configuration file /etc/raddb/mods-enabled/dynamic_clients
including configuration file /etc/raddb/mods-enabled/echo
including configuration file /etc/raddb/mods-enabled/exec
including configuration file /etc/raddb/mods-enabled/expiration
including configuration file /etc/raddb/mods-enabled/expr
including configuration file /etc/raddb/mods-enabled/files
including configuration file /etc/raddb/mods-enabled/linelog
including configuration file /etc/raddb/mods-enabled/logintime
including configuration file /etc/raddb/mods-enabled/mschap
including configuration file /etc/raddb/mods-enabled/ntlm_auth
including configuration file /etc/raddb/mods-enabled/pap
including configuration file /etc/raddb/mods-enabled/passwd
including configuration file /etc/raddb/mods-enabled/preprocess
including configuration file /etc/raddb/mods-enabled/radutmp
including configuration file /etc/raddb/mods-enabled/realm
including configuration file /etc/raddb/mods-enabled/replicate
including configuration file /etc/raddb/mods-enabled/soh
including configuration file /etc/raddb/mods-enabled/sradutmp
including configuration file /etc/raddb/mods-enabled/unix
including configuration file /etc/raddb/mods-enabled/unpack
including configuration file /etc/raddb/mods-enabled/utf8
including configuration file /etc/raddb/mods-enabled/eap
including configuration file /etc/raddb/mods-enabled/perl
including files in directory /etc/raddb/policy.d/
including configuration file /etc/raddb/policy.d/accounting
including configuration file /etc/raddb/policy.d/canonicalization
including configuration file /etc/raddb/policy.d/control
including configuration file /etc/raddb/policy.d/cui
including configuration file /etc/raddb/policy.d/debug
including configuration file /etc/raddb/policy.d/dhcp
including configuration file /etc/raddb/policy.d/eap
including configuration file /etc/raddb/policy.d/filter
including configuration file /etc/raddb/policy.d/operator-name
including files in directory /etc/raddb/sites-enabled/
including configuration file /etc/raddb/sites-enabled/default
including configuration file /etc/raddb/sites-enabled/inner-tunnel
main {
  security {
      allow_core_dumps = no
  }
}
main {
     name = "radiusd"
     prefix = "/usr/local"
     localstatedir = "/usr/local/var"
     sbindir = "/usr/local/sbin"
     logdir = "/var/log"
     run_dir = "/usr/local/var/run/radiusd"
     libdir = "/usr/local/lib"
     radacctdir = "/var/log/radacct"
     hostname_lookups = no
     max_request_time = 30
     cleanup_delay = 5
     max_requests = 1024
     pidfile = "/var/run/radiusd/radiusd.pid"
     checkrad = "/usr/local/sbin/checkrad"
     debug_level = 0
     proxy_requests = yes
  log {
      stripped_names = no
      auth = yes
      auth_badpass = yes
      auth_goodpass = yes
      colourise = yes
      msg_denied = "You are already logged in - access denied"
  }
  security {
      max_attributes = 200
      reject_delay = 1
      status_server = yes
      allow_vulnerable_openssl = "yes"
  }
}
radiusd: #### Loading Realms and Home Servers ####
  realm sumix.com {
     authhost = LOCAL
     accthost = LOCAL
  }
radiusd: #### Loading Clients ####
  client localhost {
      ipaddr = 127.0.0.1
      require_message_authenticator = no
      secret = <<< secret >>>
      shortname = "aae-vm"
   limit {
       max_connections = 16
       lifetime = 0
       idle_timeout = 30
   }
  }
radiusd: #### Instantiating modules ####
  instantiate {
   # Loaded module rlm_exec
   # Instantiating module "exec" from file /etc/raddb/mods-enabled/exec
   exec {
       wait = no
       input_pairs = "request"
       shell_escape = yes
       timeout = 10
   }
   # Loaded module rlm_expr
   # Instantiating module "expr" from file /etc/raddb/mods-enabled/expr
   expr {
       safe_characters = 
"@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /"
   }
   # Loaded module rlm_expiration
   # Instantiating module "expiration" from file 
/etc/raddb/mods-enabled/expiration
   # Loaded module rlm_logintime
   # Instantiating module "logintime" from file 
/etc/raddb/mods-enabled/logintime
   logintime {
       minimum_timeout = 60
   }
  }
  modules {
   # Loaded module rlm_always
   # Instantiating module "reject" from file /etc/raddb/mods-enabled/always
   always reject {
       rcode = "reject"
       simulcount = 0
       mpp = no
   }
   # Instantiating module "fail" from file /etc/raddb/mods-enabled/always
   always fail {
       rcode = "fail"
       simulcount = 0
       mpp = no
   }
   # Instantiating module "ok" from file /etc/raddb/mods-enabled/always
   always ok {
       rcode = "ok"
       simulcount = 0
       mpp = no
   }
   # Instantiating module "handled" from file /etc/raddb/mods-enabled/always
   always handled {
       rcode = "handled"
       simulcount = 0
       mpp = no
   }
   # Instantiating module "invalid" from file /etc/raddb/mods-enabled/always
   always invalid {
       rcode = "invalid"
       simulcount = 0
       mpp = no
   }
   # Instantiating module "userlock" from file 
/etc/raddb/mods-enabled/always
   always userlock {
       rcode = "userlock"
       simulcount = 0
       mpp = no
   }
   # Instantiating module "notfound" from file 
/etc/raddb/mods-enabled/always
   always notfound {
       rcode = "notfound"
       simulcount = 0
       mpp = no
   }
   # Instantiating module "noop" from file /etc/raddb/mods-enabled/always
   always noop {
       rcode = "noop"
       simulcount = 0
       mpp = no
   }
   # Instantiating module "updated" from file /etc/raddb/mods-enabled/always
   always updated {
       rcode = "updated"
       simulcount = 0
       mpp = no
   }
   # Loaded module rlm_attr_filter
   # Instantiating module "attr_filter.post-proxy" from file 
/etc/raddb/mods-enabled/attr_filter
   attr_filter attr_filter.post-proxy {
       filename = "/etc/raddb/mods-config/attr_filter/post-proxy"
       key = "%{Realm}"
       relaxed = no
   }
reading pairlist file /etc/raddb/mods-config/attr_filter/post-proxy
   # Instantiating module "attr_filter.pre-proxy" from file 
/etc/raddb/mods-enabled/attr_filter
   attr_filter attr_filter.pre-proxy {
       filename = "/etc/raddb/mods-config/attr_filter/pre-proxy"
       key = "%{Realm}"
       relaxed = no
   }
reading pairlist file /etc/raddb/mods-config/attr_filter/pre-proxy
   # Instantiating module "attr_filter.access_reject" from file 
/etc/raddb/mods-enabled/attr_filter
   attr_filter attr_filter.access_reject {
       filename = "/etc/raddb/mods-config/attr_filter/access_reject"
       key = "%{User-Name}"
       relaxed = no
   }
reading pairlist file /etc/raddb/mods-config/attr_filter/access_reject
   # Instantiating module "attr_filter.access_challenge" from file 
/etc/raddb/mods-enabled/attr_filter
   attr_filter attr_filter.access_challenge {
       filename = "/etc/raddb/mods-config/attr_filter/access_challenge"
       key = "%{User-Name}"
       relaxed = no
   }
reading pairlist file /etc/raddb/mods-config/attr_filter/access_challenge
   # Instantiating module "attr_filter.accounting_response" from file 
/etc/raddb/mods-enabled/attr_filter
   attr_filter attr_filter.accounting_response {
       filename = "/etc/raddb/mods-config/attr_filter/accounting_response"
       key = "%{User-Name}"
       relaxed = no
   }
reading pairlist file /etc/raddb/mods-config/attr_filter/accounting_response
   # Loaded module rlm_cache
   # Instantiating module "cache_eap" from file 
/etc/raddb/mods-enabled/cache_eap
   cache cache_eap {
       key = "%{%{control:State}:-%{%{reply:State}:-%{State}}}"
       ttl = 15
       max_entries = 16384
       epoch = 0
       add_stats = no
   }
   # Loaded module rlm_chap
   # Instantiating module "chap" from file /etc/raddb/mods-enabled/chap
   # Loaded module rlm_detail
   # Instantiating module "detail" from file /etc/raddb/mods-enabled/detail
   detail {
       filename = 
"/var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d"
       header = "%t"
       permissions = 384
       locking = no
       log_packet_header = no
   }
   # Instantiating module "auth_log" from file 
/etc/raddb/mods-enabled/detail.log
   detail auth_log {
       filename = 
"/var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d"
       header = "%t"
       permissions = 384
       locking = no
       log_packet_header = no
   }
rlm_detail (auth_log): 'User-Password' suppressed, will not appear in 
detail output
   # Instantiating module "reply_log" from file 
/etc/raddb/mods-enabled/detail.log
   detail reply_log {
       filename = 
"/var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/reply-detail-%Y%m%d"
       header = "%t"
       permissions = 384
       locking = no
       log_packet_header = no
   }
   # Instantiating module "pre_proxy_log" from file 
/etc/raddb/mods-enabled/detail.log
   detail pre_proxy_log {
       filename = 
"/var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/pre-proxy-detail-%Y%m%d"
       header = "%t"
       permissions = 384
       locking = no
       log_packet_header = no
   }
   # Instantiating module "post_proxy_log" from file 
/etc/raddb/mods-enabled/detail.log
   detail post_proxy_log {
       filename = 
"/var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/post-proxy-detail-%Y%m%d"
       header = "%t"
       permissions = 384
       locking = no
       log_packet_header = no
   }
   # Loaded module rlm_digest
   # Instantiating module "digest" from file /etc/raddb/mods-enabled/digest
   # Loaded module rlm_dhcp
   # Instantiating module "dhcp" from file /etc/raddb/mods-enabled/dhcp
   # Loaded module rlm_dynamic_clients
   # Instantiating module "dynamic_clients" from file 
/etc/raddb/mods-enabled/dynamic_clients
   # Instantiating module "echo" from file /etc/raddb/mods-enabled/echo
   exec echo {
       wait = yes
       program = "/bin/echo %{User-Name}"
       input_pairs = "request"
       output_pairs = "reply"
       shell_escape = yes
   }
   # Loaded module rlm_files
   # Instantiating module "files" from file /etc/raddb/mods-enabled/files
   files {
       filename = "/etc/raddb/mods-config/files/authorize"
       usersfile = "/etc/raddb/mods-config/files/authorize"
       acctusersfile = "/etc/raddb/mods-config/files/accounting"
       preproxy_usersfile = "/etc/raddb/mods-config/files/pre-proxy"
       compat = "cistron"
   }
reading pairlist file /etc/raddb/mods-config/files/authorize
[/etc/raddb/mods-config/files/authorize]:181 Cistron compatibility 
checks for entry DEFAULT ...
[/etc/raddb/mods-config/files/authorize]:188 Cistron compatibility 
checks for entry DEFAULT ...
[/etc/raddb/mods-config/files/authorize]:195 Cistron compatibility 
checks for entry DEFAULT ...
reading pairlist file /etc/raddb/mods-config/files/authorize
[/etc/raddb/mods-config/files/authorize]:181 Cistron compatibility 
checks for entry DEFAULT ...
[/etc/raddb/mods-config/files/authorize]:188 Cistron compatibility 
checks for entry DEFAULT ...
[/etc/raddb/mods-config/files/authorize]:195 Cistron compatibility 
checks for entry DEFAULT ...
reading pairlist file /etc/raddb/mods-config/files/accounting
reading pairlist file /etc/raddb/mods-config/files/pre-proxy
   # Loaded module rlm_linelog
   # Instantiating module "linelog" from file 
/etc/raddb/mods-enabled/linelog
   linelog {
       filename = "/var/log/linelog"
       permissions = 384
       format = "This is a log message for %{User-Name}"
       reference = "messages.%{%{Packet-Type}:-default}"
   }
   # Instantiating module "log_accounting" from file 
/etc/raddb/mods-enabled/linelog
   linelog log_accounting {
       filename = "/var/log/linelog-accounting"
       permissions = 384
       format = ""
       reference = "Accounting-Request.%{%{Acct-Status-Type}:-unknown}"
   }
   # Loaded module rlm_mschap
   # Instantiating module "mschap" from file /etc/raddb/mods-enabled/mschap
   mschap {
       use_mppe = yes
       require_encryption = no
       require_strong = no
       with_ntdomain_hack = yes
    passchange {
    }
       allow_retry = yes
   }
   # Instantiating module "ntlm_auth" from file 
/etc/raddb/mods-enabled/ntlm_auth
   exec ntlm_auth {
       wait = yes
       program = "/path/to/ntlm_auth --request-nt-key --domain=MYDOMAIN 
--username=%{mschap:User-Name} --password=%{User-Password}"
       shell_escape = yes
   }
   # Loaded module rlm_pap
   # Instantiating module "pap" from file /etc/raddb/mods-enabled/pap
   pap {
       normalise = yes
   }
   # Loaded module rlm_passwd
   # Instantiating module "etc_passwd" from file 
/etc/raddb/mods-enabled/passwd
   passwd etc_passwd {
       filename = "/etc/passwd"
       format = "*User-Name:Crypt-Password:"
       delimiter = ":"
       ignore_nislike = no
       ignore_empty = yes
       allow_multiple_keys = no
       hash_size = 100
   }
rlm_passwd: nfields: 3 keyfield 0(User-Name) listable: no
   # Loaded module rlm_preprocess
   # Instantiating module "preprocess" from file 
/etc/raddb/mods-enabled/preprocess
   preprocess {
       huntgroups = "/etc/raddb/mods-config/preprocess/huntgroups"
       hints = "/etc/raddb/mods-config/preprocess/hints"
       with_ascend_hack = no
       ascend_channels_per_line = 23
       with_ntdomain_hack = no
       with_specialix_jetstream_hack = no
       with_cisco_vsa_hack = no
       with_alvarion_vsa_hack = no
   }
reading pairlist file /etc/raddb/mods-config/preprocess/huntgroups
reading pairlist file /etc/raddb/mods-config/preprocess/hints
   # Loaded module rlm_radutmp
   # Instantiating module "radutmp" from file 
/etc/raddb/mods-enabled/radutmp
   radutmp {
       filename = "/var/log/radutmp"
       username = "%{User-Name}"
       case_sensitive = yes
       check_with_nas = yes
       permissions = 384
       caller_id = yes
   }
   # Loaded module rlm_realm
   # Instantiating module "IPASS" from file /etc/raddb/mods-enabled/realm
   realm IPASS {
       format = "prefix"
       delimiter = "/"
       ignore_default = no
       ignore_null = no
   }
   # Instantiating module "suffix" from file /etc/raddb/mods-enabled/realm
   realm suffix {
       format = "suffix"
       delimiter = "@"
       ignore_default = no
       ignore_null = no
   }
   # Instantiating module "realmpercent" from file 
/etc/raddb/mods-enabled/realm
   realm realmpercent {
       format = "suffix"
       delimiter = "%"
       ignore_default = no
       ignore_null = no
   }
   # Instantiating module "ntdomain" from file /etc/raddb/mods-enabled/realm
   realm ntdomain {
       format = "prefix"
       delimiter = "\"
       ignore_default = no
       ignore_null = no
   }
   # Loaded module rlm_replicate
   # Instantiating module "replicate" from file 
/etc/raddb/mods-enabled/replicate
   # Loaded module rlm_soh
   # Instantiating module "soh" from file /etc/raddb/mods-enabled/soh
   soh {
       dhcp = yes
   }
   # Instantiating module "sradutmp" from file 
/etc/raddb/mods-enabled/sradutmp
   radutmp sradutmp {
       filename = "/var/log/sradutmp"
       username = "%{User-Name}"
       case_sensitive = yes
       check_with_nas = yes
       permissions = 420
       caller_id = no
   }
   # Loaded module rlm_unix
   # Instantiating module "unix" from file /etc/raddb/mods-enabled/unix
   unix {
       radwtmp = "/var/log/radwtmp"
   }
   # Loaded module rlm_unpack
   # Instantiating module "unpack" from file /etc/raddb/mods-enabled/unpack
   # Loaded module rlm_utf8
   # Instantiating module "utf8" from file /etc/raddb/mods-enabled/utf8
   # Loaded module rlm_eap
   # Instantiating module "eap" from file /etc/raddb/mods-enabled/eap
   eap {
       default_eap_type = "ttls"
       timer_expire = 60
       ignore_unknown_eap_types = no
       mod_accounting_username_bug = no
       max_sessions = 2048
   }
    # Linked to sub-module rlm_eap_md5
    # Linked to sub-module rlm_eap_tls
    tls {
    }
debug: 'tls' option missing, trying to use legacy configuration
    tls {
        rsa_key_exchange = no
        dh_key_exchange = yes
        rsa_key_length = 512
        dh_key_length = 512
        verify_depth = 0
        pem_file_type = yes
        private_key_file = "/etc/raddb/certs/server.key"
        certificate_file = "/etc/raddb/certs/server.pem"
        ca_file = "/etc/raddb/certs/ca.pem"
        private_key_password = <<< secret >>>
        dh_file = "/etc/raddb/certs/dh"
        random_file = "/etc/raddb/certs/random"
        fragment_size = 1024
        include_length = yes
        check_crl = no
        cipher_list = "DEFAULT"
        ecdh_curve = "prime256v1"
     cache {
         enable = no
         lifetime = 24
         max_entries = 255
     }
     verify {
     }
     ocsp {
         enable = no
         override_cert_url = no
         use_nonce = yes
         timeout = 0
         softfail = yes
     }
    }
    # Linked to sub-module rlm_eap_ttls
    ttls {
        default_eap_type = "md5"
        copy_request_to_tunnel = no
        use_tunneled_reply = yes
        virtual_server = "inner-tunnel"
        include_length = yes
        require_client_cert = no
    }
debug: 'tls' option missing, trying to use legacy configuration
Using cached TLS configuration from previous invocation
   # Loaded module rlm_perl
   # Instantiating module "perl" from file /etc/raddb/mods-enabled/perl
   perl {
       filename = "/etc/raddb/auth_acct.pl"
       func_authorize = "authorize"
       func_authenticate = "authenticate"
       func_post_auth = "post_auth"
       func_accounting = "accounting"
       func_preacct = "preacct"
       func_checksimul = "checksimul"
       func_detach = "detach"
       func_xlat = "xlat"
       func_pre_proxy = "pre_proxy"
       func_post_proxy = "post_proxy"
       func_recv_coa = "recv_coa"
       func_send_coa = "send_coa"
   }
  } # modules
radiusd: #### Loading Virtual Servers ####
server { # from file /etc/raddb/radiusd.conf
} # server
server default { # from file /etc/raddb/sites-enabled/default
  # Loading authenticate {...}
  # Loading authorize {...}
  # Loading preacct {...}
  # Loading accounting {...}
  # Loading session {...}
  # Loading post-proxy {...}
  # Loading post-auth {...}
} # server default
server inner-tunnel { # from file /etc/raddb/sites-enabled/inner-tunnel
  # Loading authenticate {...}
  # Loading authorize {...}
  # Loading session {...}
  # Loading post-proxy {...}
  # Loading post-auth {...}
} # server inner-tunnel
radiusd: #### Opening IP addresses and Ports ####
listen {
       type = "auth"
       ipaddr = 127.0.0.1
       port = 0
    limit {
        max_connections = 16
        lifetime = 0
        idle_timeout = 30
    }
}
listen {
       type = "acct"
       ipaddr = 127.0.0.1
       port = 0
    limit {
        max_connections = 16
        lifetime = 0
        idle_timeout = 30
    }
}
listen {
       type = "auth"
       ipaddr = 127.0.0.1
       port = 18120
}
Listening on auth address 127.0.0.1 port 1812 as server default
Listening on acct address 127.0.0.1 port 1813 as server default
Listening on auth address 127.0.0.1 port 18120 as server inner-tunnel
Ready to process requests
Received Access-Request Id 210 from 127.0.0.1:53526 to 127.0.0.1:1812 
length 152
     User-Name = 'stu@sumix.com'
     NAS-Port-Type = Virtual
     Service-Type = Framed-User
     NAS-Port = 78
     NAS-Port-Id = 'rw-eap'
     NAS-IP-Address = 10.20.9.12
     Called-Station-Id = '10.20.9.12[4500]'
     Calling-Station-Id = '10.20.9.8[4500]'
     EAP-Message = 0x02000012017374754073756d69782e636f6d
     NAS-Identifier = 'strongSwan'
     Message-Authenticator = 0x7e21f90124febcaecd5acf0c5e314d77
(0) Received Access-Request packet from host 127.0.0.1 port 53526, 
id=210, length=152
(0)     User-Name = 'stu@sumix.com'
(0)     NAS-Port-Type = Virtual
(0)     Service-Type = Framed-User
(0)     NAS-Port = 78
(0)     NAS-Port-Id = 'rw-eap'
(0)     NAS-IP-Address = 10.20.9.12
(0)     Called-Station-Id = '10.20.9.12[4500]'
(0)     Calling-Station-Id = '10.20.9.8[4500]'
(0)     EAP-Message = 0x02000012017374754073756d69782e636f6d
(0)     NAS-Identifier = 'strongSwan'
(0)     Message-Authenticator = 0x7e21f90124febcaecd5acf0c5e314d77
(0) # Executing section authorize from file /etc/raddb/sites-enabled/default
(0)   authorize {
(0)  suffix : Checking for suffix after "@"
(0)  suffix : Looking up realm "sumix.com" for User-Name = "stu@sumix.com"
(0)  suffix : Found realm "sumix.com"
(0)  suffix : Adding Stripped-User-Name = "stu"
(0)  suffix : Adding Realm = "sumix.com"
(0)  suffix : Authentication realm is LOCAL
(0)   [suffix] = ok
(0)  eap : Peer sent code Response (2) ID 0 length 18
(0)  eap : EAP-Identity reply, returning 'ok' so we can short-circuit 
the rest of authorize
(0)   [eap] = ok
(0)  } #  authorize = ok
(0) Found Auth-Type = EAP
(0) # Executing group from file /etc/raddb/sites-enabled/default
(0)   authenticate {
(0)  eap : Peer sent method Identity (1)
(0)  eap : Calling eap_ttls to process EAP data
(0)  eap_ttls : Initiate
(0)  eap_ttls : Start returned 1
(0)  eap : New EAP session, adding 'State' attribute to reply 
0xc0c4b9fbc0c5ac4d
(0)   [eap] = handled
(0)  } #  authenticate = handled
(0) Sending Access-Challenge packet to host 127.0.0.1 port 53526, 
id=210, length=0
(0)     EAP-Message = 0x010100061520
(0)     Message-Authenticator = 0x00000000000000000000000000000000
(0)     State = 0xc0c4b9fbc0c5ac4d65e24895584243ab
Sending Access-Challenge Id 210 from 127.0.0.1:1812 to 127.0.0.1:53526
     EAP-Message = 0x010100061520
     Message-Authenticator = 0x00000000000000000000000000000000
     State = 0xc0c4b9fbc0c5ac4d65e24895584243ab
(0) Finished request
Waking up in 0.3 seconds.
Received Access-Request Id 211 from 127.0.0.1:53526 to 127.0.0.1:1812 
length 250
     User-Name = 'stu@sumix.com'
     NAS-Port-Type = Virtual
     Service-Type = Framed-User
     NAS-Port = 78
     NAS-Port-Id = 'rw-eap'
     NAS-IP-Address = 10.20.9.12
     Called-Station-Id = '10.20.9.12[4500]'
     Calling-Station-Id = '10.20.9.8[4500]'
     EAP-Message = 
0x0201006215800000005816030300530100004f030354350d35bcae841329e19443ce0efa98c7d90c129316c8aa1158695c3400147f000014003300670039006b0016002f003c0035003d000a01000012000d000e000c040105010601030102010101
     NAS-Identifier = 'strongSwan'
     State = 0xc0c4b9fbc0c5ac4d65e24895584243ab
     Message-Authenticator = 0xa643761fc5c9b2924729fd2a27f7a2cc
(1) Received Access-Request packet from host 127.0.0.1 port 53526, 
id=211, length=250
(1)     User-Name = 'stu@sumix.com'
(1)     NAS-Port-Type = Virtual
(1)     Service-Type = Framed-User
(1)     NAS-Port = 78
(1)     NAS-Port-Id = 'rw-eap'
(1)     NAS-IP-Address = 10.20.9.12
(1)     Called-Station-Id = '10.20.9.12[4500]'
(1)     Calling-Station-Id = '10.20.9.8[4500]'
(1)     EAP-Message = 
0x0201006215800000005816030300530100004f030354350d35bcae841329e19443ce0efa98c7d90c129316c8aa1158695c3400147f000014003300670039006b0016002f003c0035003d000a01000012000d000e000c040105010601030102010101
(1)     NAS-Identifier = 'strongSwan'
(1)     State = 0xc0c4b9fbc0c5ac4d65e24895584243ab
(1)     Message-Authenticator = 0xa643761fc5c9b2924729fd2a27f7a2cc
(1) # Executing section authorize from file /etc/raddb/sites-enabled/default
(1)   authorize {
(1)  suffix : Checking for suffix after "@"
(1)  suffix : Looking up realm "sumix.com" for User-Name = "stu@sumix.com"
(1)  suffix : Found realm "sumix.com"
(1)  suffix : Adding Stripped-User-Name = "stu"
(1)  suffix : Adding Realm = "sumix.com"
(1)  suffix : Authentication realm is LOCAL
(1)   [suffix] = ok
(1)  eap : Peer sent code Response (2) ID 1 length 98
(1)  eap : Continuing tunnel setup
(1)   [eap] = ok
(1)  } #  authorize = ok
(1) Found Auth-Type = EAP
(1) # Executing group from file /etc/raddb/sites-enabled/default
(1)   authenticate {
(1)  eap : Expiring EAP session with state 0xc0c4b9fbc0c5ac4d
(1)  eap : Finished EAP session with state 0xc0c4b9fbc0c5ac4d
(1)  eap : Previous EAP request found for state 0xc0c4b9fbc0c5ac4d, 
released from the list
(1)  eap : Peer sent method TTLS (21)
(1)  eap : EAP TTLS (21)
(1)  eap : Calling eap_ttls to process EAP data
(1)  eap_ttls : Authenticate
(1)  eap_ttls : processing EAP-TLS
   TLS Length 88
(1)  eap_ttls : Length Included
(1)  eap_ttls : eaptls_verify returned 11
(1)  eap_ttls : (other): before/accept initialization
(1)  eap_ttls : TLS_accept: before/accept initialization
(1)  eap_ttls : <<< TLS 1.0 Handshake [length 0053], ClientHello
(1)  eap_ttls : TLS_accept: SSLv3 read client hello A
(1)  eap_ttls : >>> TLS 1.0 Handshake [length 002a], ServerHello
(1)  eap_ttls : TLS_accept: SSLv3 write server hello A
(1)  eap_ttls : >>> TLS 1.0 Handshake [length 0894], Certificate
(1)  eap_ttls : TLS_accept: SSLv3 write certificate A
(1)  eap_ttls : >>> TLS 1.0 Handshake [length 020d], ServerKeyExchange
(1)  eap_ttls : TLS_accept: SSLv3 write key exchange A
(1)  eap_ttls : >>> TLS 1.0 Handshake [length 0004], ServerHelloDone
(1)  eap_ttls : TLS_accept: SSLv3 write server done A
(1)  eap_ttls : TLS_accept: SSLv3 flush data
(1)  eap_ttls : TLS_accept: Need to read more data: SSLv3 read client 
certificate A
In SSL Handshake Phase
In SSL Accept mode
(1)  eap_ttls : eaptls_process returned 13
(1)  eap : New EAP session, adding 'State' attribute to reply 
0xc0c4b9fbc1c6ac4d
(1)   [eap] = handled
(1)  } #  authenticate = handled
(1) Sending Access-Challenge packet to host 127.0.0.1 port 53526, 
id=211, length=0
(1)     EAP-Message = 
0x010203f615c000000ae3160301002a02000026030154350d35f134908e15cc9d8ae1f9b8843d5ebc829a5e3c4ccad45534b02acb0f0000330016030108940b00089000088d0003c9308203c5308202ada003020102020101300d06092a864886f70d0101050500308186310b3009060355040613025541310f300d06035504081306526164697573310d300b060355040713044b69657631133011060355040a130a53756d697820496e632e311c301a06092a864886f70d010901160d6161654073756d69782e636f6d312430220603550403131b53756d697820436572746966696361746520417574686f72697479301e170d3134313030333039353734355a170d3134313230323039353734355a3074310b3009060355040613025541310f300d0603550408130652616469757331133011060355040a130a53756d697820496e632e3121301f0603550403131853756d697820536572766572204365727469666963617465311c301a06092a864886f70d010901160d6161654073756d69782e636f6d30820122300d06092a864886f70d01010105000382010f003082010a0282010100a653008d510c3ae6faa5cae07b04988d706e8b3cbafb56659636501675bef7639fea37e28e140689aca254f066197b82c34082469e45bcb0cc699ffe69a4705af2a954ed23a7a483d499e7ce617b38c4
(1)     Message-Authenticator = 0x00000000000000000000000000000000
(1)     State = 0xc0c4b9fbc1c6ac4d65e24895584243ab
Sending Access-Challenge Id 211 from 127.0.0.1:1812 to 127.0.0.1:53526
     EAP-Message = 
0x010203f615c000000ae3160301002a02000026030154350d35f134908e15cc9d8ae1f9b8843d5ebc829a5e3c4ccad45534b02acb0f0000330016030108940b00089000088d0003c9308203c5308202ada003020102020101300d06092a864886f70d0101050500308186310b3009060355040613025541310f300d06035504081306526164697573310d300b060355040713044b69657631133011060355040a130a53756d697820496e632e311c301a06092a864886f70d010901160d6161654073756d69782e636f6d312430220603550403131b53756d697820436572746966696361746520417574686f72697479301e170d3134313030333039353734355a170d3134313230323039353734355a3074310b3009060355040613025541310f300d0603550408130652616469757331133011060355040a130a53756d697820496e632e3121301f0603550403131853756d697820536572766572204365727469666963617465311c301a06092a864886f70d010901160d6161654073756d69782e636f6d30820122300d06092a864886f70d01010105000382010f003082010a0282010100a653008d510c3ae6faa5cae07b04988d706e8b3cbafb56659636501675bef7639fea37e28e140689aca254f066197b82c34082469e45bcb0cc699ffe69a4705af2a954ed23a7a483d499e7ce617b38c
     Message-Authenticator = 0x00000000000000000000000000000000
     State = 0xc0c4b9fbc1c6ac4d65e24895584243ab
(1) Finished request
Waking up in 0.3 seconds.
Received Access-Request Id 212 from 127.0.0.1:53526 to 127.0.0.1:1812 
length 158
     User-Name = 'stu@sumix.com'
     NAS-Port-Type = Virtual
     Service-Type = Framed-User
     NAS-Port = 78
     NAS-Port-Id = 'rw-eap'
     NAS-IP-Address = 10.20.9.12
     Called-Station-Id = '10.20.9.12[4500]'
     Calling-Station-Id = '10.20.9.8[4500]'
     EAP-Message = 0x020200061500
     NAS-Identifier = 'strongSwan'
     State = 0xc0c4b9fbc1c6ac4d65e24895584243ab
     Message-Authenticator = 0x933e71380f3c065076868711d56b6aa2
(2) Received Access-Request packet from host 127.0.0.1 port 53526, 
id=212, length=158
(2)     User-Name = 'stu@sumix.com'
(2)     NAS-Port-Type = Virtual
(2)     Service-Type = Framed-User
(2)     NAS-Port = 78
(2)     NAS-Port-Id = 'rw-eap'
(2)     NAS-IP-Address = 10.20.9.12
(2)     Called-Station-Id = '10.20.9.12[4500]'
(2)     Calling-Station-Id = '10.20.9.8[4500]'
(2)     EAP-Message = 0x020200061500
(2)     NAS-Identifier = 'strongSwan'
(2)     State = 0xc0c4b9fbc1c6ac4d65e24895584243ab
(2)     Message-Authenticator = 0x933e71380f3c065076868711d56b6aa2
(2) # Executing section authorize from file /etc/raddb/sites-enabled/default
(2)   authorize {
(2)  suffix : Checking for suffix after "@"
(2)  suffix : Looking up realm "sumix.com" for User-Name = "stu@sumix.com"
(2)  suffix : Found realm "sumix.com"
(2)  suffix : Adding Stripped-User-Name = "stu"
(2)  suffix : Adding Realm = "sumix.com"
(2)  suffix : Authentication realm is LOCAL
(2)   [suffix] = ok
(2)  eap : Peer sent code Response (2) ID 2 length 6
(2)  eap : Continuing tunnel setup
(2)   [eap] = ok
(2)  } #  authorize = ok
(2) Found Auth-Type = EAP
(2) # Executing group from file /etc/raddb/sites-enabled/default
(2)   authenticate {
(2)  eap : Expiring EAP session with state 0xc0c4b9fbc1c6ac4d
(2)  eap : Finished EAP session with state 0xc0c4b9fbc1c6ac4d
(2)  eap : Previous EAP request found for state 0xc0c4b9fbc1c6ac4d, 
released from the list
(2)  eap : Peer sent method TTLS (21)
(2)  eap : EAP TTLS (21)
(2)  eap : Calling eap_ttls to process EAP data
(2)  eap_ttls : Authenticate
(2)  eap_ttls : processing EAP-TLS
(2)  eap_ttls : Received TLS ACK
(2)  eap_ttls : Received TLS ACK
(2)  eap_ttls : ACK handshake fragment handler
(2)  eap_ttls : eaptls_verify returned 1
(2)  eap_ttls : eaptls_process returned 13
(2)  eap : New EAP session, adding 'State' attribute to reply 
0xc0c4b9fbc2c7ac4d
(2)   [eap] = handled
(2)  } #  authenticate = handled
(2) Sending Access-Challenge packet to host 127.0.0.1 port 53526, 
id=212, length=0
(2)     EAP-Message = 
0x010303f615c000000ae3dd9539c81dccb967b27a8e84bb0f21e80ce6ec67dd3ce528ac40440004be308204ba308203a2a003020102020900aa5f43161b37eeb5300d06092a864886f70d0101050500308186310b3009060355040613025541310f300d06035504081306526164697573310d300b060355040713044b69657631133011060355040a130a53756d697820496e632e311c301a06092a864886f70d010901160d6161654073756d69782e636f6d312430220603550403131b53756d697820436572746966696361746520417574686f72697479301e170d3134313030333039353734355a170d3134313230323039353734355a308186310b3009060355040613025541310f300d06035504081306526164697573310d300b060355040713044b69657631133011060355040a130a53756d697820496e632e311c301a06092a864886f70d010901160d6161654073756d69782e636f6d312430220603550403131b53756d697820436572746966696361746520417574686f7269747930820122300d06092a864886f70d01010105000382010f003082010a0282010100c28fc9b88a9bf464d55f4b2eec7e5564b468ea947386e70e0fa6cb22e1a3798efcfceba9614aec3e7d806987b5bed59b38998651a05d13619aa4f9b182825706c8a8005c8aea1e56263b890125ebb1acff3fbe9eef
(2)     Message-Authenticator = 0x00000000000000000000000000000000
(2)     State = 0xc0c4b9fbc2c7ac4d65e24895584243ab
Sending Access-Challenge Id 212 from 127.0.0.1:1812 to 127.0.0.1:53526
     EAP-Message = 
0x010303f615c000000ae3dd9539c81dccb967b27a8e84bb0f21e80ce6ec67dd3ce528ac40440004be308204ba308203a2a003020102020900aa5f43161b37eeb5300d06092a864886f70d0101050500308186310b3009060355040613025541310f300d06035504081306526164697573310d300b060355040713044b69657631133011060355040a130a53756d697820496e632e311c301a06092a864886f70d010901160d6161654073756d69782e636f6d312430220603550403131b53756d697820436572746966696361746520417574686f72697479301e170d3134313030333039353734355a170d3134313230323039353734355a308186310b3009060355040613025541310f300d06035504081306526164697573310d300b060355040713044b69657631133011060355040a130a53756d697820496e632e311c301a06092a864886f70d010901160d6161654073756d69782e636f6d312430220603550403131b53756d697820436572746966696361746520417574686f7269747930820122300d06092a864886f70d01010105000382010f003082010a0282010100c28fc9b88a9bf464d55f4b2eec7e5564b468ea947386e70e0fa6cb22e1a3798efcfceba9614aec3e7d806987b5bed59b38998651a05d13619aa4f9b182825706c8a8005c8aea1e56263b890125ebb1acff3fbe9ee
     Message-Authenticator = 0x00000000000000000000000000000000
     State = 0xc0c4b9fbc2c7ac4d65e24895584243ab
(2) Finished request
Waking up in 0.3 seconds.
Received Access-Request Id 213 from 127.0.0.1:53526 to 127.0.0.1:1812 
length 158
     User-Name = 'stu@sumix.com'
     NAS-Port-Type = Virtual
     Service-Type = Framed-User
     NAS-Port = 78
     NAS-Port-Id = 'rw-eap'
     NAS-IP-Address = 10.20.9.12
     Called-Station-Id = '10.20.9.12[4500]'
     Calling-Station-Id = '10.20.9.8[4500]'
     EAP-Message = 0x020300061500
     NAS-Identifier = 'strongSwan'
     State = 0xc0c4b9fbc2c7ac4d65e24895584243ab
     Message-Authenticator = 0xaffd5a5b893d8340f08c70cdb4d1fd53
(3) Received Access-Request packet from host 127.0.0.1 port 53526, 
id=213, length=158
(3)     User-Name = 'stu@sumix.com'
(3)     NAS-Port-Type = Virtual
(3)     Service-Type = Framed-User
(3)     NAS-Port = 78
(3)     NAS-Port-Id = 'rw-eap'
(3)     NAS-IP-Address = 10.20.9.12
(3)     Called-Station-Id = '10.20.9.12[4500]'
(3)     Calling-Station-Id = '10.20.9.8[4500]'
(3)     EAP-Message = 0x020300061500
(3)     NAS-Identifier = 'strongSwan'
(3)     State = 0xc0c4b9fbc2c7ac4d65e24895584243ab
(3)     Message-Authenticator = 0xaffd5a5b893d8340f08c70cdb4d1fd53
(3) # Executing section authorize from file /etc/raddb/sites-enabled/default
(3)   authorize {
(3)  suffix : Checking for suffix after "@"
(3)  suffix : Looking up realm "sumix.com" for User-Name = "stu@sumix.com"
(3)  suffix : Found realm "sumix.com"
(3)  suffix : Adding Stripped-User-Name = "stu"
(3)  suffix : Adding Realm = "sumix.com"
(3)  suffix : Authentication realm is LOCAL
(3)   [suffix] = ok
(3)  eap : Peer sent code Response (2) ID 3 length 6
(3)  eap : Continuing tunnel setup
(3)   [eap] = ok
(3)  } #  authorize = ok
(3) Found Auth-Type = EAP
(3) # Executing group from file /etc/raddb/sites-enabled/default
(3)   authenticate {
(3)  eap : Expiring EAP session with state 0xc0c4b9fbc2c7ac4d
(3)  eap : Finished EAP session with state 0xc0c4b9fbc2c7ac4d
(3)  eap : Previous EAP request found for state 0xc0c4b9fbc2c7ac4d, 
released from the list
(3)  eap : Peer sent method TTLS (21)
(3)  eap : EAP TTLS (21)
(3)  eap : Calling eap_ttls to process EAP data
(3)  eap_ttls : Authenticate
(3)  eap_ttls : processing EAP-TLS
(3)  eap_ttls : Received TLS ACK
(3)  eap_ttls : Received TLS ACK
(3)  eap_ttls : ACK handshake fragment handler
(3)  eap_ttls : eaptls_verify returned 1
(3)  eap_ttls : eaptls_process returned 13
(3)  eap : New EAP session, adding 'State' attribute to reply 
0xc0c4b9fbc3c0ac4d
(3)   [eap] = handled
(3)  } #  authenticate = handled
(3) Sending Access-Challenge packet to host 127.0.0.1 port 53526, 
id=213, length=0
(3)     EAP-Message = 
0x01040315158000000ae3f41cba52d38dfb392f46768cad7b90f6a2d444ca4950f2ca896a55189d75cb9f8670ab0dc07e3b5729663cac320a25f08ebf9947f285368b1441461355fb05eb5939753379de9f7fdc92ebcebd9ef7f579a5b9e5269bad6b35d49a38fe51d843d68cd1c9e8def29de505b5a64c9dbb3d07209ba2fa274866f8db014606ec89ee44138511e7dfa3eaf839f6f17295d4572dcf992e11ba7810d1598d58efc87f820a6b5f67e89cddc7dbbdf1b242c01f18e4d58aa3b9c43163284219ac3cc5fd3fda573d26a56b1f545cd15ad9d815362767a924ce96ebe9d3088fd7ca0c99bddef37db71a497a62254d2486c1ab7bf886160301020d0c0002090080cc92e713074cdd998fce384c110ab6cf8d0ec5073be9131aaae92c6999d1ab5798081c90c3d16d5fc8c26ab41df81d579b89f90490f677c682316e55ff727c41155071985ba46207506faeef575064dc075d40848087a92ff39cb130829cd918ed7c1db61a5b7340b218e50859d8139cbc177b15584096baaaf6ed3154cc716b0001020080a9b657b252368ca37520d69e1e515658177d726ba8dbf78933c6991576584420ae4e3b23eb64dfb5095795438aa8f45a1fb6b35291ec791a91919faff713a99cd71bc96caff03e282e165b064870612b34034b25737d2f4d8fd9466448b2872fd3e90d1f5dda585862f07bea77
(3)     Message-Authenticator = 0x00000000000000000000000000000000
(3)     State = 0xc0c4b9fbc3c0ac4d65e24895584243ab
Sending Access-Challenge Id 213 from 127.0.0.1:1812 to 127.0.0.1:53526
     EAP-Message = 
0x01040315158000000ae3f41cba52d38dfb392f46768cad7b90f6a2d444ca4950f2ca896a55189d75cb9f8670ab0dc07e3b5729663cac320a25f08ebf9947f285368b1441461355fb05eb5939753379de9f7fdc92ebcebd9ef7f579a5b9e5269bad6b35d49a38fe51d843d68cd1c9e8def29de505b5a64c9dbb3d07209ba2fa274866f8db014606ec89ee44138511e7dfa3eaf839f6f17295d4572dcf992e11ba7810d1598d58efc87f820a6b5f67e89cddc7dbbdf1b242c01f18e4d58aa3b9c43163284219ac3cc5fd3fda573d26a56b1f545cd15ad9d815362767a924ce96ebe9d3088fd7ca0c99bddef37db71a497a62254d2486c1ab7bf886160301020d0c0002090080cc92e713074cdd998fce384c110ab6cf8d0ec5073be9131aaae92c6999d1ab5798081c90c3d16d5fc8c26ab41df81d579b89f90490f677c682316e55ff727c41155071985ba46207506faeef575064dc075d40848087a92ff39cb130829cd918ed7c1db61a5b7340b218e50859d8139cbc177b15584096baaaf6ed3154cc716b0001020080a9b657b252368ca37520d69e1e515658177d726ba8dbf78933c6991576584420ae4e3b23eb64dfb5095795438aa8f45a1fb6b35291ec791a91919faff713a99cd71bc96caff03e282e165b064870612b34034b25737d2f4d8fd9466448b2872fd3e90d1f5dda585862f07bea7
     Message-Authenticator = 0x00000000000000000000000000000000
     State = 0xc0c4b9fbc3c0ac4d65e24895584243ab
(3) Finished request
Waking up in 0.2 seconds.
Received Access-Request Id 214 from 127.0.0.1:53526 to 127.0.0.1:1812 
length 360
     User-Name = 'stu@sumix.com'
     NAS-Port-Type = Virtual
     Service-Type = Framed-User
     NAS-Port = 78
     NAS-Port-Id = 'rw-eap'
     NAS-IP-Address = 10.20.9.12
     Called-Station-Id = '10.20.9.12[4500]'
     Calling-Station-Id = '10.20.9.8[4500]'
     EAP-Message = 
0x020400d01580000000c61603010086100000820080870d51d53ff98cb3ecb9f5162629be51720f9e0780c2e39670eab2d9f194557eeaee774f9a61a3129fdda0acb0d90be20be451950ecd8c4f351ccf9f9f756d2b42ec2eba3d6ff1788bbf346d39d43f6fd44477cba332f38c4c9a0d491580dea4f58f76459d6c982f99e0417b44af43edc3431b8f5e9e5d898f15f55339596ce7140301000101160301003017095b9731b3f83f366e83bd57370d84be4cfaabd834e640537c178220ba5102757ac8908c71f17facbef365a99e89ee
     NAS-Identifier = 'strongSwan'
     State = 0xc0c4b9fbc3c0ac4d65e24895584243ab
     Message-Authenticator = 0x562098f8c6ea87c14bde8f7e4d1dba89
(4) Received Access-Request packet from host 127.0.0.1 port 53526, 
id=214, length=360
(4)     User-Name = 'stu@sumix.com'
(4)     NAS-Port-Type = Virtual
(4)     Service-Type = Framed-User
(4)     NAS-Port = 78
(4)     NAS-Port-Id = 'rw-eap'
(4)     NAS-IP-Address = 10.20.9.12
(4)     Called-Station-Id = '10.20.9.12[4500]'
(4)     Calling-Station-Id = '10.20.9.8[4500]'
(4)     EAP-Message = 
0x020400d01580000000c61603010086100000820080870d51d53ff98cb3ecb9f5162629be51720f9e0780c2e39670eab2d9f194557eeaee774f9a61a3129fdda0acb0d90be20be451950ecd8c4f351ccf9f9f756d2b42ec2eba3d6ff1788bbf346d39d43f6fd44477cba332f38c4c9a0d491580dea4f58f76459d6c982f99e0417b44af43edc3431b8f5e9e5d898f15f55339596ce7140301000101160301003017095b9731b3f83f366e83bd57370d84be4cfaabd834e640537c178220ba5102757ac8908c71f17facbef365a99e89ee
(4)     NAS-Identifier = 'strongSwan'
(4)     State = 0xc0c4b9fbc3c0ac4d65e24895584243ab
(4)     Message-Authenticator = 0x562098f8c6ea87c14bde8f7e4d1dba89
(4) # Executing section authorize from file /etc/raddb/sites-enabled/default
(4)   authorize {
(4)  suffix : Checking for suffix after "@"
(4)  suffix : Looking up realm "sumix.com" for User-Name = "stu@sumix.com"
(4)  suffix : Found realm "sumix.com"
(4)  suffix : Adding Stripped-User-Name = "stu"
(4)  suffix : Adding Realm = "sumix.com"
(4)  suffix : Authentication realm is LOCAL
(4)   [suffix] = ok
(4)  eap : Peer sent code Response (2) ID 4 length 208
(4)  eap : Continuing tunnel setup
(4)   [eap] = ok
(4)  } #  authorize = ok
(4) Found Auth-Type = EAP
(4) # Executing group from file /etc/raddb/sites-enabled/default
(4)   authenticate {
(4)  eap : Expiring EAP session with state 0xc0c4b9fbc3c0ac4d
(4)  eap : Finished EAP session with state 0xc0c4b9fbc3c0ac4d
(4)  eap : Previous EAP request found for state 0xc0c4b9fbc3c0ac4d, 
released from the list
(4)  eap : Peer sent method TTLS (21)
(4)  eap : EAP TTLS (21)
(4)  eap : Calling eap_ttls to process EAP data
(4)  eap_ttls : Authenticate
(4)  eap_ttls : processing EAP-TLS
   TLS Length 198
(4)  eap_ttls : Length Included
(4)  eap_ttls : eaptls_verify returned 11
(4)  eap_ttls : <<< TLS 1.0 Handshake [length 0086], ClientKeyExchange
(4)  eap_ttls : TLS_accept: SSLv3 read client key exchange A
(4)  eap_ttls : <<< TLS 1.0 ChangeCipherSpec [length 0001]
(4)  eap_ttls : <<< TLS 1.0 Handshake [length 0010], Finished
(4)  eap_ttls : TLS_accept: SSLv3 read finished A
(4)  eap_ttls : >>> TLS 1.0 ChangeCipherSpec [length 0001]
(4)  eap_ttls : TLS_accept: SSLv3 write change cipher spec A
(4)  eap_ttls : >>> TLS 1.0 Handshake [length 0010], Finished
(4)  eap_ttls : TLS_accept: SSLv3 write finished A
(4)  eap_ttls : TLS_accept: SSLv3 flush data
(4)  eap_ttls : (other): SSL negotiation finished successfully
SSL Connection Established
(4)  eap_ttls : eaptls_process returned 13
(4)  eap : New EAP session, adding 'State' attribute to reply 
0xc0c4b9fbc4c1ac4d
(4)   [eap] = handled
(4)  } #  authenticate = handled
(4) Sending Access-Challenge packet to host 127.0.0.1 port 53526, 
id=214, length=0
(4)     EAP-Message = 
0x0105004515800000003b1403010001011603010030ebc0e5828b98359409e3eb7e7248301dff8e8e9935e91d06971684a83cb25793d5d7931b0b1d42314ffbccfc7e89c84b
(4)     Message-Authenticator = 0x00000000000000000000000000000000
(4)     State = 0xc0c4b9fbc4c1ac4d65e24895584243ab
Sending Access-Challenge Id 214 from 127.0.0.1:1812 to 127.0.0.1:53526
     EAP-Message = 
0x0105004515800000003b1403010001011603010030ebc0e5828b98359409e3eb7e7248301dff8e8e9935e91d06971684a83cb25793d5d7931b0b1d42314ffbccfc7e89c84b
     Message-Authenticator = 0x00000000000000000000000000000000
     State = 0xc0c4b9fbc4c1ac4d65e24895584243ab
(4) Finished request
Waking up in 0.2 seconds.
Received Access-Request Id 215 from 127.0.0.1:53526 to 127.0.0.1:1812 
length 231
     User-Name = 'stu@sumix.com'
     NAS-Port-Type = Virtual
     Service-Type = Framed-User
     NAS-Port = 78
     NAS-Port-Id = 'rw-eap'
     NAS-IP-Address = 10.20.9.12
     Called-Station-Id = '10.20.9.12[4500]'
     Calling-Station-Id = '10.20.9.8[4500]'
     EAP-Message = 
0x0205004f15800000004517030100403c490996809f091ae95c95497f8cc9fa5d20049f67714f80471e3af11c8f53f9407f1235363e9369529f089c9faeb6f7617eebef5e866a0c2c33ff6295689828
     NAS-Identifier = 'strongSwan'
     State = 0xc0c4b9fbc4c1ac4d65e24895584243ab
     Message-Authenticator = 0x821116b0e2c30a5a1747b49129e8605f
(5) Received Access-Request packet from host 127.0.0.1 port 53526, 
id=215, length=231
(5)     User-Name = 'stu@sumix.com'
(5)     NAS-Port-Type = Virtual
(5)     Service-Type = Framed-User
(5)     NAS-Port = 78
(5)     NAS-Port-Id = 'rw-eap'
(5)     NAS-IP-Address = 10.20.9.12
(5)     Called-Station-Id = '10.20.9.12[4500]'
(5)     Calling-Station-Id = '10.20.9.8[4500]'
(5)     EAP-Message = 
0x0205004f15800000004517030100403c490996809f091ae95c95497f8cc9fa5d20049f67714f80471e3af11c8f53f9407f1235363e9369529f089c9faeb6f7617eebef5e866a0c2c33ff6295689828
(5)     NAS-Identifier = 'strongSwan'
(5)     State = 0xc0c4b9fbc4c1ac4d65e24895584243ab
(5)     Message-Authenticator = 0x821116b0e2c30a5a1747b49129e8605f
(5) # Executing section authorize from file /etc/raddb/sites-enabled/default
(5)   authorize {
(5)  suffix : Checking for suffix after "@"
(5)  suffix : Looking up realm "sumix.com" for User-Name = "stu@sumix.com"
(5)  suffix : Found realm "sumix.com"
(5)  suffix : Adding Stripped-User-Name = "stu"
(5)  suffix : Adding Realm = "sumix.com"
(5)  suffix : Authentication realm is LOCAL
(5)   [suffix] = ok
(5)  eap : Peer sent code Response (2) ID 5 length 79
(5)  eap : Continuing tunnel setup
(5)   [eap] = ok
(5)  } #  authorize = ok
(5) Found Auth-Type = EAP
(5) # Executing group from file /etc/raddb/sites-enabled/default
(5)   authenticate {
(5)  eap : Expiring EAP session with state 0xc0c4b9fbc4c1ac4d
(5)  eap : Finished EAP session with state 0xc0c4b9fbc4c1ac4d
(5)  eap : Previous EAP request found for state 0xc0c4b9fbc4c1ac4d, 
released from the list
(5)  eap : Peer sent method TTLS (21)
(5)  eap : EAP TTLS (21)
(5)  eap : Calling eap_ttls to process EAP data
(5)  eap_ttls : Authenticate
(5)  eap_ttls : processing EAP-TLS
   TLS Length 69
(5)  eap_ttls : Length Included
(5)  eap_ttls : eaptls_verify returned 11
(5)  eap_ttls : eaptls_process returned 7
(5)  eap_ttls : Session established.  Proceeding to decode tunneled 
attributes
(5)  eap_ttls : Got tunneled request
     EAP-Message = 0x02000012017374754073756d69782e636f6d
(5)  eap_ttls : Got tunneled identity of stu@sumix.com
(5)  eap_ttls : Setting default EAP type for tunneled EAP session
(5)  eap_ttls : Sending tunneled request
(5)  server inner-tunnel {
(5)    Request:
     EAP-Message = 0x02000012017374754073756d69782e636f6d
     User-Name = 'stu@sumix.com'
(5)  # Executing section authorize from file 
/etc/raddb/sites-enabled/inner-tunnel
(5)    authorize {
(5)   eap : Peer sent code Response (2) ID 0 length 18
(5)   eap : EAP-Identity reply, returning 'ok' so we can short-circuit 
the rest of authorize
(5)    [eap] = ok
(5)   } #  authorize = ok
(5)  Found Auth-Type = EAP
(5)  # Executing group from file /etc/raddb/sites-enabled/inner-tunnel
(5)    authenticate {
(5)   eap : Peer sent method Identity (1)
(5)   eap : Calling eap_md5 to process EAP data
(5)   eap_md5 : Issuing MD5 Challenge
(5)   eap : New EAP session, adding 'State' attribute to reply 
0xd1c37efdd1c27a33
(5)    [eap] = handled
(5)   } #  authenticate = handled
(5)    Reply:
     EAP-Message = 0x0101001604104966cc29d0e37fb0f8fbecb9f5f966da
     Message-Authenticator = 0x00000000000000000000000000000000
     State = 0xd1c37efdd1c27a33ce26defdbde2d5d4
(5)  } # server inner-tunnel
(5)  eap_ttls : Got tunneled Access-Challenge
(5)  eap : New EAP session, adding 'State' attribute to reply 
0xc0c4b9fbc5c2ac4d
(5)   [eap] = handled
(5)  } #  authenticate = handled
(5) Sending Access-Challenge packet to host 127.0.0.1 port 53526, 
id=215, length=0
(5)     EAP-Message = 
0x0106004f15800000004517030100407da87d7186c13fdd2c2740ef17584d9169564f74d33d45cdedc48bd838f307efd20432d0f02f81be384481419218742553b1b90c650eb351237b91588cc79b3c
(5)     Message-Authenticator = 0x00000000000000000000000000000000
(5)     State = 0xc0c4b9fbc5c2ac4d65e24895584243ab
Sending Access-Challenge Id 215 from 127.0.0.1:1812 to 127.0.0.1:53526
     EAP-Message = 
0x0106004f15800000004517030100407da87d7186c13fdd2c2740ef17584d9169564f74d33d45cdedc48bd838f307efd20432d0f02f81be384481419218742553b1b90c650eb351237b91588cc79b3c
     Message-Authenticator = 0x00000000000000000000000000000000
     State = 0xc0c4b9fbc5c2ac4d65e24895584243ab
(5) Finished request
Waking up in 0.2 seconds.
Received Access-Request Id 216 from 127.0.0.1:53526 to 127.0.0.1:1812 
length 231
     User-Name = 'stu@sumix.com'
     NAS-Port-Type = Virtual
     Service-Type = Framed-User
     NAS-Port = 78
     NAS-Port-Id = 'rw-eap'
     NAS-IP-Address = 10.20.9.12
     Called-Station-Id = '10.20.9.12[4500]'
     Calling-Station-Id = '10.20.9.8[4500]'
     EAP-Message = 
0x0206004f1580000000451703010040c393718df27cd394ae8039e04bbc09fa7752dca564c0841598960210a86acd4a257452776ea09f381077adebffc905558eb325a7addd9a9206f7f50ca5a5fbf5
     NAS-Identifier = 'strongSwan'
     State = 0xc0c4b9fbc5c2ac4d65e24895584243ab
     Message-Authenticator = 0xa3bd1f0b9627df52237e70ad3629fa52
(6) Received Access-Request packet from host 127.0.0.1 port 53526, 
id=216, length=231
(6)     User-Name = 'stu@sumix.com'
(6)     NAS-Port-Type = Virtual
(6)     Service-Type = Framed-User
(6)     NAS-Port = 78
(6)     NAS-Port-Id = 'rw-eap'
(6)     NAS-IP-Address = 10.20.9.12
(6)     Called-Station-Id = '10.20.9.12[4500]'
(6)     Calling-Station-Id = '10.20.9.8[4500]'
(6)     EAP-Message = 
0x0206004f1580000000451703010040c393718df27cd394ae8039e04bbc09fa7752dca564c0841598960210a86acd4a257452776ea09f381077adebffc905558eb325a7addd9a9206f7f50ca5a5fbf5
(6)     NAS-Identifier = 'strongSwan'
(6)     State = 0xc0c4b9fbc5c2ac4d65e24895584243ab
(6)     Message-Authenticator = 0xa3bd1f0b9627df52237e70ad3629fa52
(6) # Executing section authorize from file /etc/raddb/sites-enabled/default
(6)   authorize {
(6)  suffix : Checking for suffix after "@"
(6)  suffix : Looking up realm "sumix.com" for User-Name = "stu@sumix.com"
(6)  suffix : Found realm "sumix.com"
(6)  suffix : Adding Stripped-User-Name = "stu"
(6)  suffix : Adding Realm = "sumix.com"
(6)  suffix : Authentication realm is LOCAL
(6)   [suffix] = ok
(6)  eap : Peer sent code Response (2) ID 6 length 79
(6)  eap : Continuing tunnel setup
(6)   [eap] = ok
(6)  } #  authorize = ok
(6) Found Auth-Type = EAP
(6) # Executing group from file /etc/raddb/sites-enabled/default
(6)   authenticate {
(6)  eap : Expiring EAP session with state 0xd1c37efdd1c27a33
(6)  eap : Finished EAP session with state 0xc0c4b9fbc5c2ac4d
(6)  eap : Previous EAP request found for state 0xc0c4b9fbc5c2ac4d, 
released from the list
(6)  eap : Peer sent method TTLS (21)
(6)  eap : EAP TTLS (21)
(6)  eap : Calling eap_ttls to process EAP data
(6)  eap_ttls : Authenticate
(6)  eap_ttls : processing EAP-TLS
   TLS Length 69
(6)  eap_ttls : Length Included
(6)  eap_ttls : eaptls_verify returned 11
(6)  eap_ttls : eaptls_process returned 7
(6)  eap_ttls : Session established.  Proceeding to decode tunneled 
attributes
(6)  eap_ttls : Got tunneled request
     EAP-Message = 0x020100160410600a49ae5d212341b6be08f34c3de38e
(6)  eap_ttls : Sending tunneled request
(6)  server inner-tunnel {
(6)    Request:
     EAP-Message = 0x020100160410600a49ae5d212341b6be08f34c3de38e
     User-Name = 'stu@sumix.com'
     State = 0xd1c37efdd1c27a33ce26defdbde2d5d4
(6)  # Executing section authorize from file 
/etc/raddb/sites-enabled/inner-tunnel
(6)    authorize {
(6)   eap : Peer sent code Response (2) ID 1 length 22
(6)   eap : No EAP Start, assuming it's an on-going EAP conversation
(6)    [eap] = updated
(6)    [files] = noop
(6)   } #  authorize = updated
(6)  Found Auth-Type = EAP
(6)  # Executing group from file /etc/raddb/sites-enabled/inner-tunnel
(6)    authenticate {
(6)   eap : Expiring EAP session with state 0xd1c37efdd1c27a33
(6)   eap : Finished EAP session with state 0xd1c37efdd1c27a33
(6)   eap : Previous EAP request found for state 0xd1c37efdd1c27a33, 
released from the list
(6)   eap : Peer sent method MD5 (4)
(6)   eap : EAP MD5 (4)
(6)   eap : Calling eap_md5 to process EAP data
(6)   eap_md5 : Cleartext-Password is required for EAP-MD5 authentication
(6)   ERROR: eap : Failed continuing EAP MD5 (4) session. EAP sub-module 
failed
(6)   eap : Failed in EAP select
(6)    [eap] = invalid
(6)   } #  authenticate = invalid
(6)  Failed to authenticate the user
(6)  Login incorrect (eap: Failed continuing EAP MD5 (4) session. EAP 
sub-module failed): [stu@sumix.com/<via Auth-Type = EAP>] (from client 
aae-vm port 0 via TLS tunnel)
(6)  Using Post-Auth-Type Reject
(6)  # Executing group from file /etc/raddb/sites-enabled/inner-tunnel
(6)   Post-Auth-Type REJECT {
(6)   attr_filter.access_reject : EXPAND %{User-Name}
(6)   attr_filter.access_reject :    --> stu@sumix.com
(6)   attr_filter.access_reject : Matched entry DEFAULT at line 11
(6)    [attr_filter.access_reject] = updated
(6)   } # Post-Auth-Type REJECT = updated
(6)    Reply:
     EAP-Message = 0x04010004
     Message-Authenticator = 0x00000000000000000000000000000000
(6)  } # server inner-tunnel
(6)  eap_ttls : Got tunneled Access-Reject
(6)  ERROR: eap : Failed continuing EAP TTLS (21) session. EAP 
sub-module failed
(6)  eap : Failed in EAP select
(6)   [eap] = invalid
(6)  } #  authenticate = invalid
(6) Failed to authenticate the user
(6) Login incorrect (eap: Failed continuing EAP TTLS (21) session. EAP 
sub-module failed): [stu@sumix.com/<via Auth-Type = EAP>] (from client 
aae-vm port 78 cli 10.20.9.8[4500])
(6) Using Post-Auth-Type Reject
(6) # Executing group from file /etc/raddb/sites-enabled/default
(6)  Post-Auth-Type REJECT {
(6)  attr_filter.access_reject : EXPAND %{User-Name}
(6)  attr_filter.access_reject :    --> stu@sumix.com
(6)  attr_filter.access_reject : Matched entry DEFAULT at line 11
(6)   [attr_filter.access_reject] = updated
(6)  } # Post-Auth-Type REJECT = updated
(6) Delaying response for 1 seconds
Waking up in 0.2 seconds.
Waking up in 0.6 seconds.
(6) Sending delayed response
(6) Sending Access-Reject packet to host 127.0.0.1 port 53526, id=216, 
length=0
(6)     EAP-Message = 0x04060004
(6)     Message-Authenticator = 0x00000000000000000000000000000000
Sending Access-Reject Id 216 from 127.0.0.1:1812 to 127.0.0.1:53526
     EAP-Message = 0x04060004
     Message-Authenticator = 0x00000000000000000000000000000000
Waking up in 3.9 seconds.
(0) Cleaning up request packet ID 210 with timestamp +4
(1) Cleaning up request packet ID 211 with timestamp +4
(2) Cleaning up request packet ID 212 with timestamp +4
(3) Cleaning up request packet ID 213 with timestamp +4
(4) Cleaning up request packet ID 214 with timestamp +4
(5) Cleaning up request packet ID 215 with timestamp +4
(6) Cleaning up request packet ID 216 with timestamp +4
Ready to process requests

Re: Calling eap_md5 to process EAP data in inner-tunnel

Oleksandr Yermolenko