[eap] ERROR! Our request for tls was NAK'd with a request for tls. Skipping the requested type.

26 Jun 2009

      [eap] EAP NAK
[eap] ERROR! Our request for tls was NAK'd with a request for tls.  Skipping the requested type.

Hi,

having a new voip pbx (OmniPCX Enterprise 9.0) from Alcatel-Lucent, I now try to setup 802.1x with the phones, an Alcatel-Lucent IP Touch 4028 EE.

Freeradius is 2.x on a Debian 5.0.  My first attempt was with MD5, which works without any problem.
Next step is TLS, which works at 50%. Well, the client authentication of TLS works, but when I configure to do a server authentication within the IP phone´s setup, it fails.

So, here is the output from radiusd -Xf when server authentication is not added within the IP phone´s setup:

=============================================================

FreeRADIUS Version 2.1.6, for host i686-pc-linux-gnu, built on May 29 2009 at 15:54:08
Copyright (C) 1999-2009 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 v2.
Starting - reading configuration files ...
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/modules/
including configuration file /etc/raddb/modules/radutmp
including configuration file /etc/raddb/modules/pap
including configuration file /etc/raddb/modules/attr_rewrite
including configuration file /etc/raddb/modules/perl
including configuration file /etc/raddb/modules/expr
including configuration file /etc/raddb/modules/smbpasswd
including configuration file /etc/raddb/modules/otp
including configuration file /etc/raddb/modules/acct_unique
including configuration file /etc/raddb/modules/chap
including configuration file /etc/raddb/modules/krb5
including configuration file /etc/raddb/modules/files
including configuration file /etc/raddb/modules/policy
including configuration file /etc/raddb/modules/wimax
including configuration file /etc/raddb/modules/ldap
including configuration file /etc/raddb/modules/realm
including configuration file /etc/raddb/modules/mschap
including configuration file /etc/raddb/modules/linelog
including configuration file /etc/raddb/modules/sql_log
including configuration file /etc/raddb/modules/detail
including configuration file /etc/raddb/modules/digest
including configuration file /etc/raddb/modules/mac2vlan
including configuration file /etc/raddb/modules/expiration
including configuration file /etc/raddb/modules/echo
including configuration file /etc/raddb/modules/detail.example.com
including configuration file /etc/raddb/modules/counter
including configuration file /etc/raddb/modules/attr_filter
including configuration file /etc/raddb/modules/sradutmp
including configuration file /etc/raddb/modules/pam
including configuration file /etc/raddb/modules/inner-eap
including configuration file /etc/raddb/modules/smsotp
including configuration file /etc/raddb/modules/passwd
including configuration file /etc/raddb/modules/ippool
including configuration file /etc/raddb/modules/logintime
including configuration file /etc/raddb/modules/always
including configuration file /etc/raddb/modules/preprocess
including configuration file /etc/raddb/modules/sqlcounter_expire_on_login
including configuration file /etc/raddb/modules/exec
including configuration file /etc/raddb/modules/unix
including configuration file /etc/raddb/modules/etc_group
including configuration file /etc/raddb/modules/mac2ip
including configuration file /etc/raddb/modules/checkval
including configuration file /etc/raddb/modules/detail.log
including configuration file /etc/raddb/eap.conf
including configuration file /etc/raddb/policy.conf
including files in directory /etc/raddb/sites-enabled/
including configuration file /etc/raddb/sites-enabled/inner-tunnel
including configuration file /etc/raddb/sites-enabled/default
including configuration file /etc/raddb/sites-enabled/control-socket
including dictionary file /etc/raddb/dictionary
main {
        prefix = "/usr"
        localstatedir = "/var"
        logdir = "/var/log/radius"
        libdir = "/usr/lib/freeradius"
        radacctdir = "/var/log/radius/radacct"
        hostname_lookups = no
        max_request_time = 30
        cleanup_delay = 5
        max_requests = 1024
        allow_core_dumps = no
        pidfile = "/var/run/radiusd/radiusd.pid"
        checkrad = "/usr/sbin/checkrad"
        debug_level = 0
        proxy_requests = yes
 log {
        stripped_names = no
        auth = no
        auth_badpass = no
        auth_goodpass = no
 }
 security {
        max_attributes = 200
        reject_delay = 1
        status_server = yes
 }
}
radiusd: #### Loading Realms and Home Servers ####
 proxy server {
        retry_delay = 5
        retry_count = 3
        default_fallback = no
        dead_time = 120
        wake_all_if_all_dead = no
 }
 home_server localhost {
        ipaddr = 127.0.0.1
        port = 1812
        type = "auth"
        secret = "testing123"
        response_window = 20
        max_outstanding = 65536
        require_message_authenticator = no
        zombie_period = 40
        status_check = "status-server"
        ping_interval = 30
        check_interval = 30
        num_answers_to_alive = 3
        num_pings_to_alive = 3
        revive_interval = 120
        status_check_timeout = 4
        irt = 2
        mrt = 16
        mrc = 5
        mrd = 30
 }
 home_server_pool my_auth_failover {
        type = fail-over
        home_server = localhost
 }
 realm example.com {
        auth_pool = my_auth_failover
 }
 realm LOCAL {
 }
radiusd: #### Loading Clients ####
 client localhost {
        ipaddr = 127.0.0.1
        require_message_authenticator = no
        secret = "testing123"
        nastype = "other"
 }
 client 192.168.10.130 {
        require_message_authenticator = no
        secret = "password"
        shortname = "Switch1"
 }
 client 192.168.10.131 {
        require_message_authenticator = no
        secret = "password"
        shortname = "Switch2"
 }
 client 192.168.104.244 {
        require_message_authenticator = no
        secret = "password"
        shortname = "Switch3"
 }
radiusd: #### Instantiating modules ####
 instantiate {
 Module: Linked to module rlm_exec
 Module: Instantiating exec
  exec {
        wait = no
        input_pairs = "request"
        shell_escape = yes
  }
 Module: Linked to module rlm_expr
 Module: Instantiating expr
 Module: Linked to module rlm_expiration
 Module: Instantiating expiration
  expiration {
        reply-message = "Password Has Expired  "
  }
 Module: Linked to module rlm_logintime
 Module: Instantiating logintime
  logintime {
        reply-message = "You are calling outside your allowed timespan  "
        minimum-timeout = 60
  }
 }
radiusd: #### Loading Virtual Servers ####
server inner-tunnel {
 modules {
 Module: Checking authenticate {...} for more modules to load
 Module: Linked to module rlm_pap
 Module: Instantiating pap
  pap {
        encryption_scheme = "auto"
        auto_header = no
  }
 Module: Linked to module rlm_chap
 Module: Instantiating chap
 Module: Linked to module rlm_mschap
 Module: Instantiating mschap
  mschap {
        use_mppe = yes
        require_encryption = no
        require_strong = no
        with_ntdomain_hack = no
  }
 Module: Linked to module rlm_unix
 Module: Instantiating unix
  unix {
        radwtmp = "/var/log/radius/radwtmp"
  }
 Module: Linked to module rlm_eap
 Module: Instantiating eap
  eap {
        default_eap_type = "tls"
        timer_expire = 60
        ignore_unknown_eap_types = no
        cisco_accounting_username_bug = no
        max_sessions = 2048
  }
 Module: Linked to sub-module rlm_eap_md5
 Module: Instantiating eap-md5
 Module: Linked to sub-module rlm_eap_leap
 Module: Instantiating eap-leap
 Module: Linked to sub-module rlm_eap_gtc
 Module: Instantiating eap-gtc
   gtc {
        challenge = "Password: "
        auth_type = "PAP"
   }
 Module: Linked to sub-module rlm_eap_tls
 Module: Instantiating eap-tls
   tls {
        rsa_key_exchange = yes
        dh_key_exchange = yes
        rsa_key_length = 2048
        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.crt"
        CA_file = "/etc/raddb/certs/ca.crt"
        private_key_password = "password"
        dh_file = "/etc/raddb/certs/dh"
        random_file = "/etc/raddb/certs/random"
        fragment_size = 1024
        include_length = yes
        check_crl = no
        cipher_list = "DEFAULT"
        make_cert_command = "/etc/raddb/certs/bootstrap"
    cache {
        enable = no
        lifetime = 24
        max_entries = 255
    }
   }
 Module: Linked to sub-module rlm_eap_ttls
 Module: Instantiating eap-ttls
   ttls {
        default_eap_type = "md5"
        copy_request_to_tunnel = yes
        use_tunneled_reply = yes
        virtual_server = "inner-tunnel"
        include_length = yes
   }
 Module: Linked to sub-module rlm_eap_peap
 Module: Instantiating eap-peap
   peap {
        default_eap_type = "mschapv2"
        copy_request_to_tunnel = no
        use_tunneled_reply = no
        proxy_tunneled_request_as_eap = yes
        virtual_server = "inner-tunnel"
   }
 Module: Linked to sub-module rlm_eap_mschapv2
 Module: Instantiating eap-mschapv2
   mschapv2 {
        with_ntdomain_hack = no
   }
 Module: Checking authorize {...} for more modules to load
 Module: Linked to module rlm_realm
 Module: Instantiating suffix
  realm suffix {
        format = "suffix"
        delimiter = "@"
        ignore_default = no
        ignore_null = no
  }
 Module: Linked to module rlm_files
 Module: Instantiating files
  files {
        usersfile = "/etc/raddb/users"
        acctusersfile = "/etc/raddb/acct_users"
        preproxy_usersfile = "/etc/raddb/preproxy_users"
        compat = "no"
  }
 Module: Checking session {...} for more modules to load
 Module: Linked to module rlm_radutmp
 Module: Instantiating radutmp
  radutmp {
        filename = "/var/log/radius/radutmp"
        username = "%{User-Name}"
        case_sensitive = yes
        check_with_nas = yes
        perm = 384
        callerid = yes
  }
 Module: Checking post-proxy {...} for more modules to load
 Module: Checking post-auth {...} for more modules to load
 Module: Linked to module rlm_attr_filter
 Module: Instantiating attr_filter.access_reject
  attr_filter attr_filter.access_reject {
        attrsfile = "/etc/raddb/attrs.access_reject"
        key = "%{User-Name}"
  }
 } # modules
} # server
server {
 modules {
 Module: Checking authenticate {...} for more modules to load
 Module: Checking authorize {...} for more modules to load
 Module: Linked to module rlm_preprocess
 Module: Instantiating preprocess
  preprocess {
        huntgroups = "/etc/raddb/huntgroups"
        hints = "/etc/raddb/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
  }
 Module: Checking preacct {...} for more modules to load
 Module: Linked to module rlm_acct_unique
 Module: Instantiating acct_unique
  acct_unique {
        key = "User-Name, Acct-Session-Id, NAS-IP-Address, Client-IP-Address, NAS-Port"
  }
 Module: Checking accounting {...} for more modules to load
 Module: Linked to module rlm_detail
 Module: Instantiating detail
  detail {
        detailfile = "/var/log/radius/radacct/%{Client-IP-Address}/detail-%Y%m%d"
        header = "%t"
        detailperm = 384
        dirperm = 493
        locking = no
        log_packet_header = no
  }
 Module: Instantiating attr_filter.accounting_response
  attr_filter attr_filter.accounting_response {
        attrsfile = "/etc/raddb/attrs.accounting_response"
        key = "%{User-Name}"
  }
 Module: Checking session {...} for more modules to load
 Module: Checking post-proxy {...} for more modules to load
 Module: Checking post-auth {...} for more modules to load
 } # modules
} # server
radiusd: #### Opening IP addresses and Ports ####
listen {
        type = "auth"
        ipaddr = *
        port = 0
}
listen {
        type = "acct"
        ipaddr = *
        port = 0
}
listen {
        type = "control"
 listen {
        socket = "/var/run/radiusd/radiusd.sock"
 }
}
Listening on authentication address * port 1812
Listening on accounting address * port 1813
Listening on command file /var/run/radiusd/radiusd.sock
Listening on proxy address * port 1814
Ready to process requests.
rad_recv: Access-Request packet from host 192.168.10.130 port 1812, id=127, length=336
        Framed-MTU = 1480
        NAS-IP-Address = 192.168.10.130
        NAS-Identifier = "Switch"
        User-Name = "00809f858c17"
        Service-Type = Framed-User
        Framed-Protocol = PPP
        NAS-Port = 199
        NAS-Port-Type = Ethernet
        NAS-Port-Id = "I7"
        Called-Station-Id = "00-21-f7-eb-c3-00"
        Calling-Station-Id = "00-80-9f-85-8c-17"
        Connect-Info = "CONNECT Ethernet 1000Mbps Full duplex"
        Tunnel-Type:0 = VLAN
        Tunnel-Medium-Type:0 = IEEE-802
        Tunnel-Private-Group-Id:0 = "104"
        EAP-Message = 0x0244001101303038303966383538633137
        Message-Authenticator = 0x26f23798cfc04abb83fa87d210d1bc69
        MS-RAS-Vendor = 11
        HP-Attr-255 = 0x011a0000000b28
        HP-Attr-255 = 0x011a0000000b2e
        HP-Attr-255 = 0x011a0000000b3d
        HP-Attr-255 = 0x0138
        HP-Attr-255 = 0x013a
        HP-Attr-255 = 0x0140
        HP-Attr-255 = 0x0141
        HP-Attr-255 = 0x0151
+- entering group authorize {...}
++[preprocess] returns ok
[suffix] No '@' in User-Name = "00809f858c17", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 68 length 17
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
++[unix] returns notfound
[files] users: Matched entry DEFAULT at line 234
++[files] returns ok
++[expiration] returns noop
++[logintime] returns noop
[pap] WARNING! No "known good" password found for the user.  Authentication may fail because of this.
++[pap] returns noop
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] EAP Identity
[eap] processing type tls
[tls] Requiring client certificate
[tls] Initiate
[tls] Start returned 1
++[eap] returns handled
Sending Access-Challenge of id 127 to 192.168.10.130 port 1812
        Framed-Protocol = PPP
        Framed-Compression = Van-Jacobson-TCP-IP
        EAP-Message = 0x014500060d20
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0xa863225aa8262fa7eff5a1519b312199
Finished request 0.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 192.168.10.130 port 1812, id=128, length=437
        Framed-MTU = 1480
        NAS-IP-Address = 192.168.10.130
        NAS-Identifier = "Switch"
        User-Name = "00809f858c17"
        Service-Type = Framed-User
        Framed-Protocol = PPP
        NAS-Port = 199
        NAS-Port-Type = Ethernet
        NAS-Port-Id = "I7"
        Called-Station-Id = "00-21-f7-eb-c3-00"
        Calling-Station-Id = "00-80-9f-85-8c-17"
        Connect-Info = "CONNECT Ethernet 1000Mbps Full duplex"
        Tunnel-Type:0 = VLAN
        Tunnel-Medium-Type:0 = IEEE-802
        Tunnel-Private-Group-Id:0 = "104"
        State = 0xa863225aa8262fa7eff5a1519b312199
        EAP-Message = 0x024500640d800000005a160301005501000051030100000000029c3cefd84c43ff0fdd96f2139986e55316e45f34fe5e36a3caa07f00002a00660065006400630062006100600015001400120011000900080006000500040003001a0019001800170100
        Message-Authenticator = 0xca28b57e66136938c479c4f7c87ca2b9
        MS-RAS-Vendor = 11
        HP-Attr-255 = 0x011a0000000b28
        HP-Attr-255 = 0x011a0000000b2e
        HP-Attr-255 = 0x011a0000000b3d
        HP-Attr-255 = 0x0138
        HP-Attr-255 = 0x013a
        HP-Attr-255 = 0x0140
        HP-Attr-255 = 0x0141
        HP-Attr-255 = 0x0151
+- entering group authorize {...}
++[preprocess] returns ok
[suffix] No '@' in User-Name = "00809f858c17", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 69 length 100
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
++[unix] returns notfound
[files] users: Matched entry DEFAULT at line 234
++[files] returns ok
++[expiration] returns noop
++[logintime] returns noop
++[pap] returns noop
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/tls
[eap] processing type tls
[tls] Authenticate
[tls] processing EAP-TLS
  TLS Length 90
[tls] Length Included
[tls] eaptls_verify returned 11
[tls]     (other): before/accept initialization
[tls]     TLS_accept: before/accept initialization
[tls] <<< TLS 1.0 Handshake [length 0055], ClientHello
[tls]     TLS_accept: SSLv3 read client hello A
[tls] >>> TLS 1.0 Handshake [length 002a], ServerHello
[tls]     TLS_accept: SSLv3 write server hello A
[tls] >>> TLS 1.0 Handshake [length 03e2], Certificate
[tls]     TLS_accept: SSLv3 write certificate A
[tls] >>> TLS 1.0 Handshake [length 00c2], CertificateRequest
[tls]     TLS_accept: SSLv3 write certificate request A
[tls]     TLS_accept: SSLv3 flush data
[tls]     TLS_accept: Need to read more data: SSLv3 read client certificate A
In SSL Handshake Phase
In SSL Accept mode
[tls] eaptls_process returned 13
++[eap] returns handled
Sending Access-Challenge of id 128 to 192.168.10.130 port 1812
        Framed-Protocol = PPP
        Framed-Compression = Van-Jacobson-TCP-IP
        EAP-Message = 0x014604000dc0000004dd160301002a0200002603014a44ba02833ff1fa625811eb9f39e6ef6f67526e67e8ee04ebffa1b749e56ff80000090016030103e20b0003de0003db0003d8308203d4308202bc020104300d06092a864886f70d01010505003081af310b30090603550406130244453110300e0603550407130742616d62657267312c302a060355040a13234f74746f2d4672696564726963682d556e697665727369746165742042616d6265726731163014060355040b130d52656368656e7a656e7472756d311c301a060355040313134b6f6d6d756e696b6174696f6e736e65747a65312a302806092a864886f70d010901161b6e65747a
        EAP-Message = 0x2d7365727669636540756e692d62616d626572672e6465301e170d3039303632363131333831325a170d3336313131313131333831325a3081af310b30090603550406130244453110300e0603550407130742616d62657267312c302a060355040a13234f74746f2d4672696564726963682d556e697665727369746165742042616d6265726731163014060355040b130d52656368656e7a656e7472756d311c301a060355040313134b6f6d6d756e696b6174696f6e736e65747a65312a302806092a864886f70d010901161b6e65747a2d7365727669636540756e692d62616d626572672e646530820122300d06092a864886f70d010101050003
        EAP-Message = 0x82010f003082010a0282010100bdfe6eadd2eb98a40254308cecc6ae20cf243c0c8006842b54e3f584836d32feb01a3defad2df56e44f3e914eed1638e9743aad8ce964cf59dea4a21ea2643a2c2fe689c4e4f0ec30440a53f21039d6f53fa1f1ccbd18de6cf6d54041b21335042ede6508fb50983159e8bc8392936682c76053230369d77d8f7021b4851f3220263819145f78d98593bd488d874ecb5ba2179a888a746d8725c0aa910412904f876716322c44d90fc02e1aded3c6b3be48920b0998e5910bc835b75d592d6f3ccc2866952bf3d1c40b4799a527b54353338fb7cd7cdd0acbd42a1c7904a5a32d366704e95923c9d826ed49de49160e7
        EAP-Message = 0xcad3317d8cf0cd4ebdc62a92d3a5a4410203010001300d06092a864886f70d010105050003820101008b4b93d819eac0c24d526cff8f76dbfd7da85921a4c96d7394eb33b2c660de21961039fe54b96b9f708711fe658df81616db866aed2ed9ec4b42a6e0b54f33c129e92421926cba6674b2611e14081cadd9b6a8401c082ef12a84d33bd4c08fafeeadb98dc182b597d173d36b2556bae344eefa8ea24c703f3568001716188eee3c920092204fb530ffa2e6de64f18c929c4e351f84ec80120001ab08be1b0863a1866d8ce8a3561ec6a08e421e386e9015234829c87b64f1ba6b0a5c1302b3e80a735db35c696c37940eedf1fe240ea7773eb35d
        EAP-Message = 0x710afb0e1495d38c42da7dd3
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0xa863225aa9252fa7eff5a1519b312199
Finished request 1.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 192.168.10.130 port 1812, id=129, length=343
        Framed-MTU = 1480
        NAS-IP-Address = 192.168.10.130
        NAS-Identifier = "Switch"
        User-Name = "00809f858c17"
        Service-Type = Framed-User
        Framed-Protocol = PPP
        NAS-Port = 199
        NAS-Port-Type = Ethernet
        NAS-Port-Id = "I7"
        Called-Station-Id = "00-21-f7-eb-c3-00"
        Calling-Station-Id = "00-80-9f-85-8c-17"
        Connect-Info = "CONNECT Ethernet 1000Mbps Full duplex"
        Tunnel-Type:0 = VLAN
        Tunnel-Medium-Type:0 = IEEE-802
        Tunnel-Private-Group-Id:0 = "104"
        State = 0xa863225aa9252fa7eff5a1519b312199
        EAP-Message = 0x024600060d00
        Message-Authenticator = 0x5a31886be829f7fe67e6f24f7d17cd3f
        MS-RAS-Vendor = 11
        HP-Attr-255 = 0x011a0000000b28
        HP-Attr-255 = 0x011a0000000b2e
        HP-Attr-255 = 0x011a0000000b3d
        HP-Attr-255 = 0x0138
        HP-Attr-255 = 0x013a
        HP-Attr-255 = 0x0140
        HP-Attr-255 = 0x0141
        HP-Attr-255 = 0x0151
+- entering group authorize {...}
++[preprocess] returns ok
[suffix] No '@' in User-Name = "00809f858c17", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 70 length 6
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
++[unix] returns notfound
[files] users: Matched entry DEFAULT at line 234
++[files] returns ok
++[expiration] returns noop
++[logintime] returns noop
++[pap] returns noop
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/tls
[eap] processing type tls
[tls] Authenticate
[tls] processing EAP-TLS
[tls] Received TLS ACK
[tls] ACK handshake fragment handler
[tls] eaptls_verify returned 1
[tls] eaptls_process returned 13
++[eap] returns handled
Sending Access-Challenge of id 129 to 192.168.10.130 port 1812
        Framed-Protocol = PPP
        Framed-Compression = Van-Jacobson-TCP-IP
        EAP-Message = 0x014700f10d80000004dd8a8ab4bce56d175b1c0969bdd410271ff5999d0d1d3fb011bdfbe4504764c0b116030100c20d0000ba0301024000b400b23081af310b30090603550406130244453110300e0603550407130742616d62657267312c302a060355040a13234f74746f2d4672696564726963682d556e697665727369746165742042616d6265726731163014060355040b130d52656368656e7a656e7472756d311c301a060355040313134b6f6d6d756e696b6174696f6e736e65747a65312a302806092a864886f70d010901161b6e65747a2d7365727669636540756e692d62616d626572672e64650e000000
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0xa863225aaa242fa7eff5a1519b312199
Finished request 2.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 192.168.10.130 port 1812, id=130, length=1657
        Framed-MTU = 1480
        NAS-IP-Address = 192.168.10.130
        NAS-Identifier = "Switch"
        User-Name = "00809f858c17"
        Service-Type = Framed-User
        Framed-Protocol = PPP
        NAS-Port = 199
        NAS-Port-Type = Ethernet
        NAS-Port-Id = "I7"
        Called-Station-Id = "00-21-f7-eb-c3-00"
        Calling-Station-Id = "00-80-9f-85-8c-17"
        Connect-Info = "CONNECT Ethernet 1000Mbps Full duplex"
        Tunnel-Type:0 = VLAN
        Tunnel-Medium-Type:0 = IEEE-802
        Tunnel-Private-Group-Id:0 = "104"
        State = 0xa863225aaa242fa7eff5a1519b312199
        EAP-Message = 0x0247051e0dc00000061816030103ca0b0003c60003c30003c0308203bc308202a4020103300d06092a864886f70d01010505003081af310b30090603550406130244453110300e0603550407130742616d62657267312c302a060355040a13234f74746f2d4672696564726963682d556e697665727369746165742042616d6265726731163014060355040b130d52656368656e7a656e7472756d311c301a060355040313134b6f6d6d756e696b6174696f6e736e65747a65312a302806092a864886f70d010901161b6e65747a2d7365727669636540756e692d62616d626572672e6465301e170d3039303632363039323433355a170d3336313131
        EAP-Message = 0x313039323433355a308197310b30090603550406130244453110300e0603550407130742616d62657267312c302a060355040a13234f74746f2d4672696564726963682d556e697665727369746165742042616d62657267310d300b060355040b130433383530310d300b0603550403130433383530312a302806092a864886f70d010901161b6e65747a2d7365727669636540756e692d62616d626572672e646530820122300d06092a864886f70d01010105000382010f003082010a0282010100c0222e5a4de33d2567e193a028faf18d14a3798ec34a9449e44e36fc566051e4ed048ae75dab354b9bf5f36cef04a3a9a5ff1603101654d51d8f
        EAP-Message = 0x9912d806a75d89d3c89e227fe47bb1fd322cd39c97fab7290bbcef4e3af3d3710ca4a58b83bb8bc5edb4801d031c9da0136c646dc4c87c20cbb8ccf8578f89ba46679b1aba3b062528dd2f2591fb415012639bd24613cd1a91e6f2b5f0301e14092e85bde894b6633366492c9327f37e3b20a3a397e023749258f9c3d18bcaacfd03b0acf27f8c47dee5dd3dde4dd89a4a8ba166f7011d8ff95d2ef3b46af904100105be753df839c6f89e07dfea4ffb432781d9a4cc3c114f7b2b9d28026698c26caaabfeff0203010001300d06092a864886f70d0101050500038201010040bd27cdc3fe8ebbecbbabe6bbc6012d95325b282bd5d6141ef01de35a93
        EAP-Message = 0xbda30284026bf82bd4b7302ada1f7db843beb15748b09d57d3d160756aafaeb9ebdc2cd1897bab69f4315e3a66d7141070cbf17d3d4a536844742e7d07076409c6455c6ed6f3ad38ead74e050e8cc01b4fc67c0c47400a6bf3ca648f586487f8be1e29ce6964759c17c0d479c983adb53017f797782ff9c7beabde8c56a66d7ead135254646856150954c16e393753af575376185f438694b1d31d41f59f284488fc933aa47445908197ab17b1e85e0043b9bf263ad25e1dc33c87a1864adce038c63f571cb212f24a1c1d5b6331b2a7def9b54b9ecce69c2cace0d6ca651f9c48c61603010106100001020100817df4135e744b8d13a99590deaa677d
        EAP-Message = 0x37fc121dc3f4696fcca12897bb86eba8563076e826d52ef7b61b794f087ab6a877b52fe6274385c6bcbb797fb611220196d8250e319e6eae41aeb3abf5a613b204b8811cce8d352ebd1708574164f195fa60425e3ac01454ec488364aba1804b8e60a3cc60cb93ac3579ca1294ceabbc01c23cc3e479df5e4e41eaecf0edc5664b2781b102668727ca0012c1a365b62bd799d3c5bbc34c4a1119029eadf8453325bac40c06c8a7dd265bcbb0ab22073763fc8991313ff80eddefbdcde52676c0e1f171a030f5d53b6266c70413f4271c4c26046df2e7df2fc809431e6f551b71ae8dd0efabda83a712266bf4533627ef16030101060f000102010023b8
        EAP-Message = 0xafb637c54c0f2af5ce0b900abaa00583a06ef6f041d6bdd639497450a2f527e4a0b53e41ee93ef1311eab231c6
        Message-Authenticator = 0xa32aab76eea9d3033e8ea581033ddf23
        MS-RAS-Vendor = 11
        HP-Attr-255 = 0x011a0000000b28
        HP-Attr-255 = 0x011a0000000b2e
        HP-Attr-255 = 0x011a0000000b3d
        HP-Attr-255 = 0x0138
        HP-Attr-255 = 0x013a
        HP-Attr-255 = 0x0140
        HP-Attr-255 = 0x0141
        HP-Attr-255 = 0x0151
+- entering group authorize {...}
++[preprocess] returns ok
[suffix] No '@' in User-Name = "00809f858c17", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 71 length 253
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
++[unix] returns notfound
[files] users: Matched entry DEFAULT at line 234
++[files] returns ok
++[expiration] returns noop
++[logintime] returns noop
++[pap] returns noop
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/tls
[eap] processing type tls
[tls] Authenticate
[tls] processing EAP-TLS
  TLS Length 1560
[tls] Received EAP-TLS First Fragment of the message
[tls] eaptls_verify returned 9
[tls] eaptls_process returned 13
++[eap] returns handled
Sending Access-Challenge of id 130 to 192.168.10.130 port 1812
        Framed-Protocol = PPP
        Framed-Compression = Van-Jacobson-TCP-IP
        EAP-Message = 0x014800060d00
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0xa863225aab2b2fa7eff5a1519b312199
Finished request 3.
Going to the next request
Waking up in 3.7 seconds.
rad_recv: Access-Request packet from host 192.168.10.130 port 1812, id=131, length=605
        Framed-MTU = 1480
        NAS-IP-Address = 192.168.10.130
        NAS-Identifier = "Switch"
        User-Name = "00809f858c17"
        Service-Type = Framed-User
        Framed-Protocol = PPP
        NAS-Port = 199
        NAS-Port-Type = Ethernet
        NAS-Port-Id = "I7"
        Called-Station-Id = "00-21-f7-eb-c3-00"
        Calling-Station-Id = "00-80-9f-85-8c-17"
        Connect-Info = "CONNECT Ethernet 1000Mbps Full duplex"
        Tunnel-Type:0 = VLAN
        Tunnel-Medium-Type:0 = IEEE-802
        Tunnel-Private-Group-Id:0 = "104"
        State = 0xa863225aab2b2fa7eff5a1519b312199
        EAP-Message = 0x0248010a0d006cf05c22983f5e85fd525dfe92d95419f25766448e1322728a0dee8b4ddfb9e4741715a06e8c2fab8754d710170cb04971e7c47f6813a5e552f763ac9fdabdb8816d7d8d672dc75db96e1bd284837cbdf4b7fcb453b0c3304639aeb7e3e805c531c46b87f6fd8b92c254762433beaf1b665789cf12e5de2b93884d5c92ffaf7299070caac45e5e6998a8c71a0e894e075e20532e4c0d1f2d14bcc4ad39861b4d968218111d799f50b9b166db5f842d4f69f84df6086171d95ca7bc613f03e14fd5a85bd5d0761b5e41ba615eaf3d79eca3140301000101160301002840a21745ad3abb7e4006c40f0fd0f67c40c30b1bf9342cc55b91a7
        EAP-Message = 0x14e12d8625cc5ce37e5e548243
        Message-Authenticator = 0x5d76a81c99d9ed8d117658f6693d21f8
        MS-RAS-Vendor = 11
        HP-Attr-255 = 0x011a0000000b28
        HP-Attr-255 = 0x011a0000000b2e
        HP-Attr-255 = 0x011a0000000b3d
        HP-Attr-255 = 0x0138
        HP-Attr-255 = 0x013a
        HP-Attr-255 = 0x0140
        HP-Attr-255 = 0x0141
        HP-Attr-255 = 0x0151
+- entering group authorize {...}
++[preprocess] returns ok
[suffix] No '@' in User-Name = "00809f858c17", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 72 length 253
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
++[unix] returns notfound
[files] users: Matched entry DEFAULT at line 234
++[files] returns ok
++[expiration] returns noop
++[logintime] returns noop
++[pap] returns noop
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/tls
[eap] processing type tls
[tls] Authenticate
[tls] processing EAP-TLS
[tls] eaptls_verify returned 7
[tls] Done initial handshake
[tls] <<< TLS 1.0 Handshake [length 03ca], Certificate
[tls] chain-depth=1,
[tls] error=0
[tls] --> User-Name = 00809f858c17
[tls] --> BUF-Name = 
[tls] --> subject = /C=DE/
[tls] --> issuer  = /C=DE/
[tls] --> verify return:1
[tls] chain-depth=0,
[tls] error=0
[tls] --> User-Name = 00809f858c17
[tls] --> BUF-Name = 3850
[tls] --> subject = /C=DE/L=[tls] --> issuer  = /C=DE/L=
[tls] --> verify return:1
[tls]     TLS_accept: SSLv3 read client certificate A
[tls] <<< TLS 1.0 Handshake [length 0106], ClientKeyExchange
[tls]     TLS_accept: SSLv3 read client key exchange A
[tls] <<< TLS 1.0 Handshake [length 0106], CertificateVerify
[tls]     TLS_accept: SSLv3 read certificate verify A
[tls] <<< TLS 1.0 ChangeCipherSpec [length 0001]
[tls] <<< TLS 1.0 Handshake [length 0010], Finished
[tls]     TLS_accept: SSLv3 read finished A
[tls] >>> TLS 1.0 ChangeCipherSpec [length 0001]
[tls]     TLS_accept: SSLv3 write change cipher spec A
[tls] >>> TLS 1.0 Handshake [length 0010], Finished
[tls]     TLS_accept: SSLv3 write finished A
[tls]     TLS_accept: SSLv3 flush data
[tls]     (other): SSL negotiation finished successfully
SSL Connection Established
[tls] eaptls_process returned 13
++[eap] returns handled
Sending Access-Challenge of id 131 to 192.168.10.130 port 1812
        Framed-Protocol = PPP
        Framed-Compression = Van-Jacobson-TCP-IP
        EAP-Message = 0x0149003d0d800000003314030100010116030100284751a33290290d3f84335c77caabe21228593b3c56db90e09d9bb1e672ef3a5285b5e7638d2931e5
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0xa863225aac2a2fa7eff5a1519b312199
Finished request 4.
Going to the next request
Waking up in 3.6 seconds.
rad_recv: Access-Request packet from host 192.168.10.130 port 1812, id=132, length=343
        Framed-MTU = 1480
        NAS-IP-Address = 192.168.10.130
        NAS-Identifier = "Switch"
        User-Name = "00809f858c17"
        Service-Type = Framed-User
        Framed-Protocol = PPP
        NAS-Port = 199
        NAS-Port-Type = Ethernet
        NAS-Port-Id = "I7"
        Called-Station-Id = "00-21-f7-eb-c3-00"
        Calling-Station-Id = "00-80-9f-85-8c-17"
        Connect-Info = "CONNECT Ethernet 1000Mbps Full duplex"
        Tunnel-Type:0 = VLAN
        Tunnel-Medium-Type:0 = IEEE-802
        Tunnel-Private-Group-Id:0 = "104"
        State = 0xa863225aac2a2fa7eff5a1519b312199
        EAP-Message = 0x024900060d00
        Message-Authenticator = 0xd9f31890976547a84f346a88f7c1d87f
        MS-RAS-Vendor = 11
        HP-Attr-255 = 0x011a0000000b28
        HP-Attr-255 = 0x011a0000000b2e
        HP-Attr-255 = 0x011a0000000b3d
        HP-Attr-255 = 0x0138
        HP-Attr-255 = 0x013a
        HP-Attr-255 = 0x0140
        HP-Attr-255 = 0x0141
        HP-Attr-255 = 0x0151
+- entering group authorize {...}
++[preprocess] returns ok
[suffix] No '@' in User-Name = "00809f858c17", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 73 length 6
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
++[unix] returns notfound
[files] users: Matched entry DEFAULT at line 234
++[files] returns ok
++[expiration] returns noop
++[logintime] returns noop
++[pap] returns noop
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/tls
[eap] processing type tls
[tls] Authenticate
[tls] processing EAP-TLS
[tls] Received TLS ACK
[tls] ACK handshake is finished
[tls] eaptls_verify returned 3
[tls] eaptls_process returned 3
[tls] Adding user data to cached session
[eap] Freeing handler
++[eap] returns ok
+- entering group post-auth {...}
++[exec] returns noop
Sending Access-Accept of id 132 to 192.168.10.130 port 1812
        Framed-Protocol = PPP
        Framed-Compression = Van-Jacobson-TCP-IP
        MS-MPPE-Recv-Key = 0x78b733f877a98c69f4197d25508c9528eb2cd0d68686ce27dffeb875d0550248
        MS-MPPE-Send-Key = 0x5893ecdda559f6e70bafffb3088f4329608a138b74c62db3bf4eba8a187daf2d
        EAP-Message = 0x03490004
        Message-Authenticator = 0x00000000000000000000000000000000
        User-Name = "00809f858c17"
Finished request 5.
Going to the next request
Waking up in 3.6 seconds.
Cleaning up request 0 ID 127 with timestamp +2
Cleaning up request 1 ID 128 with timestamp +2
Cleaning up request 2 ID 129 with timestamp +2
Waking up in 1.2 seconds.
Cleaning up request 3 ID 130 with timestamp +4
Cleaning up request 4 ID 131 with timestamp +4
Cleaning up request 5 ID 132 with timestamp +4
Ready to process requests.

=============================================================================================================================
As soon as I enable "Server Authentication" wthin the IP phone, it fails:
=============================================================================================================================

Going to the next request
Ready to process requests.
rad_recv: Access-Request packet from host 192.168.10.130 port 1812, id=146, length=336
        Framed-MTU = 1480
        NAS-IP-Address = 192.168.10.130
        NAS-Identifier = "Switch"
        User-Name = "00809f858c17"
        Service-Type = Framed-User
        Framed-Protocol = PPP
        NAS-Port = 199
        NAS-Port-Type = Ethernet
        NAS-Port-Id = "I7"
        Called-Station-Id = "00-21-f7-eb-c3-00"
        Calling-Station-Id = "00-80-9f-85-8c-17"
        Connect-Info = "CONNECT Ethernet 1000Mbps Full duplex"
        Tunnel-Type:0 = VLAN
        Tunnel-Medium-Type:0 = IEEE-802
        Tunnel-Private-Group-Id:0 = "104"
        EAP-Message = 0x0217001101303038303966383538633137
        Message-Authenticator = 0xb2b310ea9fb4000f3c2a436a6646b653
        MS-RAS-Vendor = 11
        HP-Attr-255 = 0x011a0000000b28
        HP-Attr-255 = 0x011a0000000b2e
        HP-Attr-255 = 0x011a0000000b3d
        HP-Attr-255 = 0x0138
        HP-Attr-255 = 0x013a
        HP-Attr-255 = 0x0140
        HP-Attr-255 = 0x0141
        HP-Attr-255 = 0x0151
+- entering group authorize {...}
++[preprocess] returns ok
[suffix] No '@' in User-Name = "00809f858c17", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 23 length 17
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
++[unix] returns notfound
[files] users: Matched entry DEFAULT at line 234
++[files] returns ok
++[expiration] returns noop
++[logintime] returns noop
[pap] WARNING! No "known good" password found for the user.  Authentication may fail because of this.
++[pap] returns noop
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] EAP Identity
[eap] processing type tls
[tls] Requiring client certificate
[tls] Initiate
[tls] Start returned 1
++[eap] returns handled
Sending Access-Challenge of id 146 to 192.168.10.130 port 1812
        Framed-Protocol = PPP
        Framed-Compression = Van-Jacobson-TCP-IP
        EAP-Message = 0x011800060d20
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x750d139875151e34b18bc5eb9140ffe1
Finished request 9.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 192.168.10.130 port 1812, id=147, length=343
        Framed-MTU = 1480
        NAS-IP-Address = 192.168.10.130
        NAS-Identifier = "Switch"
        User-Name = "00809f858c17"
        Service-Type = Framed-User
        Framed-Protocol = PPP
        NAS-Port = 199
        NAS-Port-Type = Ethernet
        NAS-Port-Id = "I7"
        Called-Station-Id = "00-21-f7-eb-c3-00"
        Calling-Station-Id = "00-80-9f-85-8c-17"
        Connect-Info = "CONNECT Ethernet 1000Mbps Full duplex"
        Tunnel-Type:0 = VLAN
        Tunnel-Medium-Type:0 = IEEE-802
        Tunnel-Private-Group-Id:0 = "104"
        State = 0x750d139875151e34b18bc5eb9140ffe1
        EAP-Message = 0x02180006030d
        Message-Authenticator = 0xc861eecfeba7db7c00683c189e63b265
        MS-RAS-Vendor = 11
        HP-Attr-255 = 0x011a0000000b28
        HP-Attr-255 = 0x011a0000000b2e
        HP-Attr-255 = 0x011a0000000b3d
        HP-Attr-255 = 0x0138
        HP-Attr-255 = 0x013a
        HP-Attr-255 = 0x0140
        HP-Attr-255 = 0x0141
        HP-Attr-255 = 0x0151
+- entering group authorize {...}
++[preprocess] returns ok
[suffix] No '@' in User-Name = "00809f858c17", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 24 length 6
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
++[unix] returns notfound
[files] users: Matched entry DEFAULT at line 234
++[files] returns ok
++[expiration] returns noop
++[logintime] returns noop
[pap] WARNING! No "known good" password found for the user.  Authentication may fail because of this.
++[pap] returns noop
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP NAK
[eap] ERROR! Our request for tls was NAK'd with a request for tls.  Skipping the requested type.
[eap] No common EAP types found.
[eap] Failed in EAP select
++[eap] returns invalid
Failed to authenticate the user.
Using Post-Auth-Type Reject
+- entering group REJECT {...}
[attr_filter.access_reject]     expand: %{User-Name} -> 00809f858c17
 attr_filter: Matched entry DEFAULT at line 11
++[attr_filter.access_reject] returns updated
Delaying reject of request 10 for 1 seconds
Going to the next request
Waking up in 0.9 seconds.
Sending delayed reject for request 10
Sending Access-Reject of id 147 to 192.168.10.130 port 1812
        EAP-Message = 0x04180004
        Message-Authenticator = 0x00000000000000000000000000000000
Waking up in 3.9 seconds.
Cleaning up request 9 ID 146 with timestamp +131
Waking up in 1.0 seconds.
Cleaning up request 10 ID 147 with timestamp +131
Ready to process requests.

Well, what´s going wrong?

Michael

excelsio＠gmx.net

excelsio＠gmx.net

tags

participants (1)