Hello,
at our university we're using CISCO APs with EAP-TTLS and everythings works just fine. But at home I tryed to build the same with my Apple Airport Extreme and it's not really working...
I configured my iBook for the airport the same way like for the CISCO AP, so I don't think it's a problem at the client. I'm using freeradius-1.0.2 on debian unstable from tarball because of the strange tls-bindings in the offical debian package...
When I try to authenticate for the first time I have to accept the certificate for the tls-tunnel. Afterwards I enter my username and password and everything seems to be okay. The 802.1x apple-window I counting my online-minutes, but I can't get any signalstrength information from the AP or send receive pakets via the AP. I think I not really connected. The airport syslog isn't very helpfull, it's just telling me that I'm connected... nothing more... Could there be some problems with the wpa keys or any other reason why my pakets disappear somewhere?
In the users file I have nothing more than: ahzf Auth-Type := Local, User-Password == "1234"
The radiusd -A -X output:
Thu May 12 03:29:07 2005 : Info: Starting - reading configuration files ...
Thu May 12 03:29:07 2005 : Debug: reread_config: reading radiusd.conf
Thu May 12 03:29:07 2005 : Debug: Config: including file: /usr/local/etc/raddb/proxy.conf
Thu May 12 03:29:07 2005 : Debug: Config: including file: /usr/local/etc/raddb/clients.conf
Thu May 12 03:29:07 2005 : Debug: Config: including file: /usr/local/etc/raddb/snmp.conf
Thu May 12 03:29:07 2005 : Debug: Config: including file: /usr/local/etc/raddb/eap.conf
Thu May 12 03:29:07 2005 : Debug: Config: including file: /usr/local/etc/raddb/sql.conf
Thu May 12 03:29:07 2005 : Debug: main: prefix = "/usr/local"
Thu May 12 03:29:07 2005 : Debug: main: localstatedir = "/usr/local/var"
Thu May 12 03:29:07 2005 : Debug: main: logdir = "/usr/local/var/log/radius"
Thu May 12 03:29:07 2005 : Debug: main: libdir = "/usr/local/lib"
Thu May 12 03:29:07 2005 : Debug: main: radacctdir = "/usr/local/var/log/radius/radacct"
Thu May 12 03:29:07 2005 : Debug: main: hostname_lookups = no
Thu May 12 03:29:07 2005 : Debug: main: max_request_time = 30
Thu May 12 03:29:07 2005 : Debug: main: cleanup_delay = 5
Thu May 12 03:29:07 2005 : Debug: main: max_requests = 1024
Thu May 12 03:29:07 2005 : Debug: main: delete_blocked_requests = 0
Thu May 12 03:29:07 2005 : Debug: main: port = 0
Thu May 12 03:29:07 2005 : Debug: main: allow_core_dumps = no
Thu May 12 03:29:07 2005 : Debug: main: log_stripped_names = no
Thu May 12 03:29:07 2005 : Debug: main: log_file = "/usr/local/var/log/radius/radius.log"
Thu May 12 03:29:07 2005 : Debug: main: log_auth = no
Thu May 12 03:29:07 2005 : Debug: main: log_auth_badpass = no
Thu May 12 03:29:07 2005 : Debug: main: log_auth_goodpass = no
Thu May 12 03:29:07 2005 : Debug: main: pidfile = "/usr/local/var/run/radiusd/radiusd.pid"
Thu May 12 03:29:07 2005 : Debug: main: user = "(null)"
Thu May 12 03:29:07 2005 : Debug: main: group = "(null)"
Thu May 12 03:29:07 2005 : Debug: main: usercollide = no
Thu May 12 03:29:07 2005 : Debug: main: lower_user = "no"
Thu May 12 03:29:07 2005 : Debug: main: lower_pass = "no"
Thu May 12 03:29:07 2005 : Debug: main: nospace_user = "no"
Thu May 12 03:29:07 2005 : Debug: main: nospace_pass = "no"
Thu May 12 03:29:07 2005 : Debug: main: checkrad = "/usr/local/sbin/checkrad"
Thu May 12 03:29:07 2005 : Debug: main: proxy_requests = yes
Thu May 12 03:29:07 2005 : Debug: proxy: retry_delay = 5
Thu May 12 03:29:07 2005 : Debug: proxy: retry_count = 3
Thu May 12 03:29:07 2005 : Debug: proxy: synchronous = no
Thu May 12 03:29:07 2005 : Debug: proxy: default_fallback = yes
Thu May 12 03:29:07 2005 : Debug: proxy: dead_time = 120
Thu May 12 03:29:07 2005 : Debug: proxy: post_proxy_authorize = yes
Thu May 12 03:29:07 2005 : Debug: proxy: wake_all_if_all_dead = no
Thu May 12 03:29:07 2005 : Debug: security: max_attributes = 200
Thu May 12 03:29:07 2005 : Debug: security: reject_delay = 1
Thu May 12 03:29:07 2005 : Debug: security: status_server = no
Thu May 12 03:29:07 2005 : Debug: main: debug_level = 0
Thu May 12 03:29:07 2005 : Debug: read_config_files: reading dictionary
Thu May 12 03:29:07 2005 : Debug: read_config_files: reading naslist
Thu May 12 03:29:07 2005 : Info: Using deprecated naslist file. Support for this will go away soon.
Thu May 12 03:29:07 2005 : Debug: read_config_files: reading clients
Thu May 12 03:29:07 2005 : Debug: read_config_files: reading realms
Thu May 12 03:29:07 2005 : Debug: radiusd: entering modules setup
Thu May 12 03:29:07 2005 : Debug: Module: Library search path is /usr/local/lib
Thu May 12 03:29:07 2005 : Debug: Module: Loaded exec
Thu May 12 03:29:07 2005 : Debug: exec: wait = yes
Thu May 12 03:29:07 2005 : Debug: exec: program = "(null)"
Thu May 12 03:29:07 2005 : Debug: exec: input_pairs = "request"
Thu May 12 03:29:07 2005 : Debug: exec: output_pairs = "(null)"
Thu May 12 03:29:07 2005 : Debug: exec: packet_type = "(null)"
Thu May 12 03:29:07 2005 : Info: rlm_exec: Wait=yes but no output defined. Did you mean output=none?
Thu May 12 03:29:07 2005 : Debug: Module: Instantiated exec (exec)
Thu May 12 03:29:07 2005 : Debug: Module: Loaded expr
Thu May 12 03:29:07 2005 : Debug: Module: Instantiated expr (expr)
Thu May 12 03:29:07 2005 : Debug: Module: Loaded PAP
Thu May 12 03:29:07 2005 : Debug: pap: encryption_scheme = "crypt"
Thu May 12 03:29:07 2005 : Debug: Module: Instantiated pap (pap)
Thu May 12 03:29:07 2005 : Debug: Module: Loaded eap
Thu May 12 03:29:07 2005 : Debug: eap: default_eap_type = "ttls"
Thu May 12 03:29:07 2005 : Debug: eap: timer_expire = 60
Thu May 12 03:29:07 2005 : Debug: eap: ignore_unknown_eap_types = no
Thu May 12 03:29:07 2005 : Debug: eap: cisco_accounting_username_bug = no
Thu May 12 03:29:07 2005 : Debug: rlm_eap: Loaded and initialized type md5
Thu May 12 03:29:07 2005 : Debug: rlm_eap: Loaded and initialized type leap
Thu May 12 03:29:07 2005 : Debug: gtc: challenge = "Password: "
Thu May 12 03:29:07 2005 : Debug: gtc: auth_type = "PAP"
Thu May 12 03:29:07 2005 : Debug: rlm_eap: Loaded and initialized type gtc
Thu May 12 03:29:07 2005 : Debug: tls: rsa_key_exchange = no
Thu May 12 03:29:07 2005 : Debug: tls: dh_key_exchange = yes
Thu May 12 03:29:07 2005 : Debug: tls: rsa_key_length = 512
Thu May 12 03:29:07 2005 : Debug: tls: dh_key_length = 512
Thu May 12 03:29:07 2005 : Debug: tls: verify_depth = 0
Thu May 12 03:29:07 2005 : Debug: tls: CA_path = "(null)"
Thu May 12 03:29:07 2005 : Debug: tls: pem_file_type = yes
Thu May 12 03:29:07 2005 : Debug: tls: private_key_file = "/usr/local/etc/raddb/certs/cert-srv.pem"
Thu May 12 03:29:07 2005 : Debug: tls: certificate_file = "/usr/local/etc/raddb/certs/cert-srv.pem"
Thu May 12 03:29:07 2005 : Debug: tls: CA_file = "/usr/local/etc/raddb/certs/demoCA/cacert.pem"
Thu May 12 03:29:07 2005 : Debug: tls: private_key_password = "whatever"
Thu May 12 03:29:07 2005 : Debug: tls: dh_file = "/usr/local/etc/raddb/certs/dh"
Thu May 12 03:29:07 2005 : Debug: tls: random_file = "/usr/local/etc/raddb/certs/random"
Thu May 12 03:29:07 2005 : Debug: tls: fragment_size = 1024
Thu May 12 03:29:07 2005 : Debug: tls: include_length = yes
Thu May 12 03:29:07 2005 : Debug: tls: check_crl = no
Thu May 12 03:29:07 2005 : Debug: tls: check_cert_cn = "(null)"
Thu May 12 03:29:07 2005 : Debug: rlm_eap: Loaded and initialized type tls
Thu May 12 03:29:07 2005 : Debug: ttls: default_eap_type = "md5"
Thu May 12 03:29:07 2005 : Debug: ttls: copy_request_to_tunnel = yes
Thu May 12 03:29:07 2005 : Debug: ttls: use_tunneled_reply = yes
Thu May 12 03:29:07 2005 : Debug: rlm_eap: Loaded and initialized type ttls
Thu May 12 03:29:07 2005 : Debug: mschapv2: with_ntdomain_hack = no
Thu May 12 03:29:07 2005 : Debug: rlm_eap: Loaded and initialized type mschapv2
Thu May 12 03:29:07 2005 : Debug: Module: Instantiated eap (eap)
Thu May 12 03:29:07 2005 : Debug: Module: Loaded preprocess
Thu May 12 03:29:07 2005 : Debug: preprocess: huntgroups = "/usr/local/etc/raddb/huntgroups"
Thu May 12 03:29:07 2005 : Debug: preprocess: hints = "/usr/local/etc/raddb/hints"
Thu May 12 03:29:07 2005 : Debug: preprocess: with_ascend_hack = no
Thu May 12 03:29:07 2005 : Debug: preprocess: ascend_channels_per_line = 23
Thu May 12 03:29:07 2005 : Debug: preprocess: with_ntdomain_hack = no
Thu May 12 03:29:07 2005 : Debug: preprocess: with_specialix_jetstream_hack = no
Thu May 12 03:29:07 2005 : Debug: preprocess: with_cisco_vsa_hack = no
Thu May 12 03:29:07 2005 : Debug: Module: Instantiated preprocess (preprocess)
Thu May 12 03:29:07 2005 : Debug: Module: Loaded files
Thu May 12 03:29:07 2005 : Debug: files: usersfile = "/usr/local/etc/raddb/users"
Thu May 12 03:29:07 2005 : Debug: files: acctusersfile = "/usr/local/etc/raddb/acct_users"
Thu May 12 03:29:07 2005 : Debug: files: preproxy_usersfile = "/usr/local/etc/raddb/preproxy_users"
Thu May 12 03:29:07 2005 : Debug: files: compat = "no"
Thu May 12 03:29:07 2005 : Debug: Module: Instantiated files (files)
Thu May 12 03:29:07 2005 : Debug: Module: Loaded Acct-Unique-Session-Id
Thu May 12 03:29:07 2005 : Debug: acct_unique: key = "User-Name, Acct-Session-Id, NAS-IP-Address, Client-IP-Address, NAS-Port"
Thu May 12 03:29:07 2005 : Debug: Module: Instantiated acct_unique (acct_unique)
Thu May 12 03:29:07 2005 : Debug: Module: Loaded realm
Thu May 12 03:29:07 2005 : Debug: realm: format = "suffix"
Thu May 12 03:29:07 2005 : Debug: realm: delimiter = "@"
Thu May 12 03:29:07 2005 : Debug: realm: ignore_default = no
Thu May 12 03:29:07 2005 : Debug: realm: ignore_null = no
Thu May 12 03:29:07 2005 : Debug: Module: Instantiated realm (suffix)
Thu May 12 03:29:07 2005 : Debug: Module: Loaded detail
Thu May 12 03:29:07 2005 : Debug: detail: detailfile = "/usr/local/var/log/radius/radacct/%{Client-IP-Address}/detail-%Y%m%d"
Thu May 12 03:29:07 2005 : Debug: detail: detailperm = 384
Thu May 12 03:29:07 2005 : Debug: detail: dirperm = 493
Thu May 12 03:29:07 2005 : Debug: detail: locking = no
Thu May 12 03:29:07 2005 : Debug: Module: Instantiated detail (detail)
Thu May 12 03:29:07 2005 : Debug: Module: Loaded System
Thu May 12 03:29:07 2005 : Debug: unix: cache = no
Thu May 12 03:29:07 2005 : Debug: unix: passwd = "(null)"
Thu May 12 03:29:07 2005 : Debug: unix: shadow = "(null)"
Thu May 12 03:29:07 2005 : Debug: unix: group = "(null)"
Thu May 12 03:29:07 2005 : Debug: unix: radwtmp = "/usr/local/var/log/radius/radwtmp"
Thu May 12 03:29:07 2005 : Debug: unix: usegroup = no
Thu May 12 03:29:07 2005 : Debug: unix: cache_reload = 600
Thu May 12 03:29:07 2005 : Debug: Module: Instantiated unix (unix)
Thu May 12 03:29:07 2005 : Debug: Module: Loaded radutmp
Thu May 12 03:29:07 2005 : Debug: radutmp: filename = "/usr/local/var/log/radius/radutmp"
Thu May 12 03:29:07 2005 : Debug: radutmp: username = "%{User-Name}"
Thu May 12 03:29:07 2005 : Debug: radutmp: case_sensitive = yes
Thu May 12 03:29:07 2005 : Debug: radutmp: check_with_nas = yes
Thu May 12 03:29:07 2005 : Debug: radutmp: perm = 384
Thu May 12 03:29:07 2005 : Debug: radutmp: callerid = yes
Thu May 12 03:29:07 2005 : Debug: Module: Instantiated radutmp (radutmp)
Thu May 12 03:29:07 2005 : Debug: Listening on authentication *:1812
Thu May 12 03:29:07 2005 : Debug: Listening on accounting *:1813
Thu May 12 03:29:07 2005 : Debug: Listening on proxy *:1814
Thu May 12 03:29:07 2005 : Info: Ready to process requests.
rad_recv: Access-Request packet from host 141.24.44.109:1024, id=44, length=192
Framed-MTU = 1466
NAS-IP-Address = 10.0.1.1
NAS-Identifier = "ahzfnet AP1"
User-Name = "ahzf-intern"
Service-Type = Framed-User
NAS-Port = 256
NAS-Port-Type = Ethernet
NAS-Port-Id = "wl0"
Called-Station-Id = "00-11-24-06-2d-e1"
Calling-Station-Id = "00-0d-93-86-5f-aa"
Connect-Info = "CONNECT Ethernet 54Mbps Half duplex"
EAP-Message = 0x022b00100161687a662d696e7465726e
Message-Authenticator = 0x217c1b8348128b645236df246a53c6b9
Thu May 12 03:29:16 2005 : Debug: Processing the authorize section of radiusd.conf
Thu May 12 03:29:16 2005 : Debug: modcall: entering group authorize for request 0
Thu May 12 03:29:16 2005 : Debug: modsingle[authorize]: calling preprocess (rlm_preprocess) for request 0
Thu May 12 03:29:16 2005 : Debug: modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 0
Thu May 12 03:29:16 2005 : Debug: modcall[authorize]: module "preprocess" returns ok for request 0
Thu May 12 03:29:16 2005 : Debug: modsingle[authorize]: calling eap (rlm_eap) for request 0
Thu May 12 03:29:16 2005 : Debug: rlm_eap: EAP packet type response id 43 length 16
Thu May 12 03:29:16 2005 : Debug: rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
Thu May 12 03:29:16 2005 : Debug: modsingle[authorize]: returned from eap (rlm_eap) for request 0
Thu May 12 03:29:16 2005 : Debug: modcall[authorize]: module "eap" returns updated for request 0
Thu May 12 03:29:16 2005 : Debug: modsingle[authorize]: calling files (rlm_files) for request 0
Thu May 12 03:29:16 2005 : Debug: users: Matched entry DEFAULT at line 227
Thu May 12 03:29:16 2005 : Debug: modsingle[authorize]: returned from files (rlm_files) for request 0
Thu May 12 03:29:16 2005 : Debug: modcall[authorize]: module "files" returns ok for request 0
Thu May 12 03:29:16 2005 : Debug: modcall: group authorize returns updated for request 0
Thu May 12 03:29:16 2005 : Debug: rad_check_password: Found Auth-Type EAP
Thu May 12 03:29:16 2005 : Debug: auth: type "EAP"
Thu May 12 03:29:16 2005 : Debug: Processing the authenticate section of radiusd.conf
Thu May 12 03:29:16 2005 : Debug: modcall: entering group authenticate for request 0
Thu May 12 03:29:16 2005 : Debug: modsingle[authenticate]: calling eap (rlm_eap) for request 0
Thu May 12 03:29:16 2005 : Debug: rlm_eap: EAP Identity
Thu May 12 03:29:16 2005 : Debug: rlm_eap: processing type tls
Thu May 12 03:29:16 2005 : Debug: rlm_eap_tls: Initiate
Thu May 12 03:29:16 2005 : Debug: rlm_eap_tls: Start returned 1
Thu May 12 03:29:16 2005 : Debug: modsingle[authenticate]: returned from eap (rlm_eap) for request 0
Thu May 12 03:29:16 2005 : Debug: modcall[authenticate]: module "eap" returns handled for request 0
Thu May 12 03:29:16 2005 : Debug: modcall: group authenticate returns handled for request 0
Sending Access-Challenge of id 44 to 141.24.44.109:1024
Service-Type == Login-User
EAP-Message = 0x012c00061520
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x05e16b9dd83c563331c41e8d21ccfe39
Thu May 12 03:29:16 2005 : Debug: Finished request 0
Thu May 12 03:29:16 2005 : Debug: Going to the next request
Thu May 12 03:29:16 2005 : Debug: --- Walking the entire request list ---
Thu May 12 03:29:16 2005 : Debug: Waking up in 6 seconds...
rad_recv: Access-Request packet from host 141.24.44.109:1024, id=45, length=296
Framed-MTU = 1466
NAS-IP-Address = 10.0.1.1
NAS-Identifier = "ahzfnet AP1"
User-Name = "ahzf-intern"
Service-Type = Framed-User
NAS-Port = 256
NAS-Port-Type = Ethernet
NAS-Port-Id = "wl0"
Called-Station-Id = "00-11-24-06-2d-e1"
Calling-Station-Id = "00-0d-93-86-5f-aa"
Connect-Info = "CONNECT Ethernet 54Mbps Half duplex"
State = 0x05e16b9dd83c563331c41e8d21ccfe39
EAP-Message = 0x022c006615800000005c16030100570100005303014282b176481715e20902430085e6579c256e570026aba1039720ddbb5c8156ef0
Message-Authenticator = 0x0657d7f87c9cfd3a8a4b034b839e854a
Thu May 12 03:29:16 2005 : Debug: Processing the authorize section of radiusd.conf
Thu May 12 03:29:16 2005 : Debug: modcall: entering group authorize for request 1
Thu May 12 03:29:16 2005 : Debug: modsingle[authorize]: calling preprocess (rlm_preprocess) for request 1
Thu May 12 03:29:16 2005 : Debug: modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 1
Thu May 12 03:29:16 2005 : Debug: modcall[authorize]: module "preprocess" returns ok for request 1
Thu May 12 03:29:16 2005 : Debug: modsingle[authorize]: calling eap (rlm_eap) for request 1
Thu May 12 03:29:16 2005 : Debug: rlm_eap: EAP packet type response id 44 length 102
Thu May 12 03:29:16 2005 : Debug: rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
Thu May 12 03:29:16 2005 : Debug: modsingle[authorize]: returned from eap (rlm_eap) for request 1
Thu May 12 03:29:16 2005 : Debug: modcall[authorize]: module "eap" returns updated for request 1
Thu May 12 03:29:16 2005 : Debug: modsingle[authorize]: calling files (rlm_files) for request 1
Thu May 12 03:29:16 2005 : Debug: users: Matched entry DEFAULT at line 227
Thu May 12 03:29:16 2005 : Debug: modsingle[authorize]: returned from files (rlm_files) for request 1
Thu May 12 03:29:16 2005 : Debug: modcall[authorize]: module "files" returns ok for request 1
Thu May 12 03:29:16 2005 : Debug: modcall: group authorize returns updated for request 1
Thu May 12 03:29:16 2005 : Debug: rad_check_password: Found Auth-Type EAP
Thu May 12 03:29:16 2005 : Debug: auth: type "EAP"
Thu May 12 03:29:16 2005 : Debug: Processing the authenticate section of radiusd.conf
Thu May 12 03:29:16 2005 : Debug: modcall: entering group authenticate for request 1
Thu May 12 03:29:16 2005 : Debug: modsingle[authenticate]: calling eap (rlm_eap) for request 1
Thu May 12 03:29:16 2005 : Debug: rlm_eap: Request found, released from the list
Thu May 12 03:29:16 2005 : Debug: rlm_eap: EAP/ttls
Thu May 12 03:29:16 2005 : Debug: rlm_eap: processing type ttls
Thu May 12 03:29:16 2005 : Debug: rlm_eap_ttls: Authenticate
Thu May 12 03:29:16 2005 : Debug: rlm_eap_tls: processing TLS
Thu May 12 03:29:16 2005 : Info: rlm_eap_tls: Length Included
Thu May 12 03:29:16 2005 : Debug: eaptls_verify returned 11
Thu May 12 03:29:16 2005 : Info: (other): before/accept initialization
Thu May 12 03:29:16 2005 : Info: TLS_accept: before/accept initialization
Thu May 12 03:29:16 2005 : Debug: rlm_eap_tls: <<< TLS 1.0 Handshake [length 0057], ClientHello
Thu May 12 03:29:16 2005 : Info: TLS_accept: SSLv3 read client hello A
Thu May 12 03:29:16 2005 : Debug: rlm_eap_tls: >>> TLS 1.0 Handshake [length 004a], ServerHello
Thu May 12 03:29:16 2005 : Info: TLS_accept: SSLv3 write server hello A
Thu May 12 03:29:16 2005 : Debug: rlm_eap_tls: >>> TLS 1.0 Handshake [length 07b6], Certificate
Thu May 12 03:29:16 2005 : Info: TLS_accept: SSLv3 write certificate A
Thu May 12 03:29:16 2005 : Debug: rlm_eap_tls: >>> TLS 1.0 Handshake [length 0004], ServerHelloDone
Thu May 12 03:29:16 2005 : Info: TLS_accept: SSLv3 write server done A
Thu May 12 03:29:16 2005 : Info: TLS_accept: SSLv3 flush data
Thu May 12 03:29:16 2005 : Error: TLS_accept:error in SSLv3 read client certificate A
Thu May 12 03:29:16 2005 : Debug: In SSL Handshake Phase
Thu May 12 03:29:16 2005 : Debug: In SSL Accept mode
Thu May 12 03:29:16 2005 : Debug: eaptls_process returned 13
Thu May 12 03:29:16 2005 : Debug: modsingle[authenticate]: returned from eap (rlm_eap) for request 1
Thu May 12 03:29:16 2005 : Debug: modcall[authenticate]: module "eap" returns handled for request 1
Thu May 12 03:29:16 2005 : Debug: modcall: group authenticate returns handled for request 1
Sending Access-Challenge of id 45 to 141.24.44.109:1024
Service-Type == Login-User
EAP-Message = 0x012d040a15c000000813160301004a0200004603014282b16c935d042a5d0b355220a1b655f6d2a273c025c31169139990c1df1f1a2
EAP-Message = 0x652e562e310d300b060355040b13046572697331223020060355040313193830322e317820436c69656e74206365727469666963617
EAP-Message = 0x0b060355040b1304657269733120301e060355040313173830322e317820526f6f74206365727469666963617465312f302d06092a8
EAP-Message = 0x03010001a317301530130603551d25040c300a06082b06010505070301300d06092a864886f70d010104050003818100b5ff327b185
EAP-Message = 0x656e3110300e06035504071307496c6d656e61753139
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xcc4dc2329af72b4361a68055e2649a53
Thu May 12 03:29:16 2005 : Debug: Finished request 1
Thu May 12 03:29:16 2005 : Debug: Going to the next request
Thu May 12 03:29:16 2005 : Debug: Waking up in 6 seconds...
rad_recv: Access-Request packet from host 141.24.44.109:1024, id=46, length=200
Framed-MTU = 1466
NAS-IP-Address = 10.0.1.1
NAS-Identifier = "ahzfnet AP1"
User-Name = "ahzf-intern"
Service-Type = Framed-User
NAS-Port = 256
NAS-Port-Type = Ethernet
NAS-Port-Id = "wl0"
Called-Station-Id = "00-11-24-06-2d-e1"
Calling-Station-Id = "00-0d-93-86-5f-aa"
Connect-Info = "CONNECT Ethernet 54Mbps Half duplex"
State = 0xcc4dc2329af72b4361a68055e2649a53
EAP-Message = 0x022d00061500
Message-Authenticator = 0xd3d9b5f12789d69fda0703adc23add67
Thu May 12 03:29:16 2005 : Debug: Processing the authorize section of radiusd.conf
Thu May 12 03:29:16 2005 : Debug: modcall: entering group authorize for request 2
Thu May 12 03:29:16 2005 : Debug: modsingle[authorize]: calling preprocess (rlm_preprocess) for request 2
Thu May 12 03:29:16 2005 : Debug: modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 2
Thu May 12 03:29:16 2005 : Debug: modcall[authorize]: module "preprocess" returns ok for request 2
Thu May 12 03:29:16 2005 : Debug: modsingle[authorize]: calling eap (rlm_eap) for request 2
Thu May 12 03:29:16 2005 : Debug: rlm_eap: EAP packet type response id 45 length 6
Thu May 12 03:29:16 2005 : Debug: rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
Thu May 12 03:29:16 2005 : Debug: modsingle[authorize]: returned from eap (rlm_eap) for request 2
Thu May 12 03:29:16 2005 : Debug: modcall[authorize]: module "eap" returns updated for request 2
Thu May 12 03:29:16 2005 : Debug: modsingle[authorize]: calling files (rlm_files) for request 2
Thu May 12 03:29:16 2005 : Debug: users: Matched entry DEFAULT at line 227
Thu May 12 03:29:16 2005 : Debug: modsingle[authorize]: returned from files (rlm_files) for request 2
Thu May 12 03:29:16 2005 : Debug: modcall[authorize]: module "files" returns ok for request 2
Thu May 12 03:29:16 2005 : Debug: modcall: group authorize returns updated for request 2
Thu May 12 03:29:16 2005 : Debug: rad_check_password: Found Auth-Type EAP
Thu May 12 03:29:16 2005 : Debug: auth: type "EAP"
Thu May 12 03:29:16 2005 : Debug: Processing the authenticate section of radiusd.conf
Thu May 12 03:29:16 2005 : Debug: modcall: entering group authenticate for request 2
Thu May 12 03:29:16 2005 : Debug: modsingle[authenticate]: calling eap (rlm_eap) for request 2
Thu May 12 03:29:16 2005 : Debug: rlm_eap: Request found, released from the list
Thu May 12 03:29:16 2005 : Debug: rlm_eap: EAP/ttls
Thu May 12 03:29:16 2005 : Debug: rlm_eap: processing type ttls
Thu May 12 03:29:16 2005 : Debug: rlm_eap_ttls: Authenticate
Thu May 12 03:29:16 2005 : Debug: rlm_eap_tls: processing TLS
Thu May 12 03:29:16 2005 : Info: rlm_eap_tls: Received EAP-TLS ACK message
Thu May 12 03:29:16 2005 : Debug: rlm_eap_tls: ack handshake fragment handler
Thu May 12 03:29:16 2005 : Debug: eaptls_verify returned 1
Thu May 12 03:29:16 2005 : Debug: eaptls_process returned 13
Thu May 12 03:29:16 2005 : Debug: modsingle[authenticate]: returned from eap (rlm_eap) for request 2
Thu May 12 03:29:16 2005 : Debug: modcall[authenticate]: module "eap" returns handled for request 2
Thu May 12 03:29:16 2005 : Debug: modcall: group authenticate returns handled for request 2
Sending Access-Challenge of id 46 to 141.24.44.109:1024
Service-Type == Login-User
EAP-Message = 0x012e040a15c0000008133037060355040a1330466f72736368756e677367656d65696e73636861667420656c656b74726f6e6973636
EAP-Message = 0x7531393037060355040a1330466f72736368756e677367656d65696e73636861667420656c656b74726f6e6973636865204d6564696
EAP-Message = 0x3268e48a985e59ed617eefb259a08706d89069784f2b7d33f1ce65ce1828d948187306eb7983544074b4612609ced8ae207ca3326a0
EAP-Message = 0x65204d656469656e20652e562e310d300b060355040b13046572697331223020060355040313193830322e317820436c69656e74206
EAP-Message = 0xf5c5e0716a4937fc89ac34959601a76371d70463c2d1
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x84479330933de0fa7e19813419e004c6
Thu May 12 03:29:16 2005 : Debug: Finished request 2
Thu May 12 03:29:16 2005 : Debug: Going to the next request
Thu May 12 03:29:16 2005 : Debug: Waking up in 6 seconds...
rad_recv: Access-Request packet from host 141.24.44.109:1024, id=47, length=200
Framed-MTU = 1466
NAS-IP-Address = 10.0.1.1
NAS-Identifier = "ahzfnet AP1"
User-Name = "ahzf-intern"
Service-Type = Framed-User
NAS-Port = 256
NAS-Port-Type = Ethernet
NAS-Port-Id = "wl0"
Called-Station-Id = "00-11-24-06-2d-e1"
Calling-Station-Id = "00-0d-93-86-5f-aa"
Connect-Info = "CONNECT Ethernet 54Mbps Half duplex"
State = 0x84479330933de0fa7e19813419e004c6
EAP-Message = 0x022e00061500
Message-Authenticator = 0x588fc6de95b8239090e29c4c6db235cd
Thu May 12 03:29:16 2005 : Debug: Processing the authorize section of radiusd.conf
Thu May 12 03:29:16 2005 : Debug: modcall: entering group authorize for request 3
Thu May 12 03:29:16 2005 : Debug: modsingle[authorize]: calling preprocess (rlm_preprocess) for request 3
Thu May 12 03:29:16 2005 : Debug: modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 3
Thu May 12 03:29:16 2005 : Debug: modcall[authorize]: module "preprocess" returns ok for request 3
Thu May 12 03:29:16 2005 : Debug: modsingle[authorize]: calling eap (rlm_eap) for request 3
Thu May 12 03:29:16 2005 : Debug: rlm_eap: EAP packet type response id 46 length 6
Thu May 12 03:29:16 2005 : Debug: rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
Thu May 12 03:29:16 2005 : Debug: modsingle[authorize]: returned from eap (rlm_eap) for request 3
Thu May 12 03:29:16 2005 : Debug: modcall[authorize]: module "eap" returns updated for request 3
Thu May 12 03:29:16 2005 : Debug: modsingle[authorize]: calling files (rlm_files) for request 3
Thu May 12 03:29:16 2005 : Debug: users: Matched entry DEFAULT at line 227
Thu May 12 03:29:16 2005 : Debug: modsingle[authorize]: returned from files (rlm_files) for request 3
Thu May 12 03:29:16 2005 : Debug: modcall[authorize]: module "files" returns ok for request 3
Thu May 12 03:29:16 2005 : Debug: modcall: group authorize returns updated for request 3
Thu May 12 03:29:16 2005 : Debug: rad_check_password: Found Auth-Type EAP
Thu May 12 03:29:16 2005 : Debug: auth: type "EAP"
Thu May 12 03:29:16 2005 : Debug: Processing the authenticate section of radiusd.conf
Thu May 12 03:29:16 2005 : Debug: modcall: entering group authenticate for request 3
Thu May 12 03:29:16 2005 : Debug: modsingle[authenticate]: calling eap (rlm_eap) for request 3
Thu May 12 03:29:16 2005 : Debug: rlm_eap: Request found, released from the list
Thu May 12 03:29:16 2005 : Debug: rlm_eap: EAP/ttls
Thu May 12 03:29:16 2005 : Debug: rlm_eap: processing type ttls
Thu May 12 03:29:16 2005 : Debug: rlm_eap_ttls: Authenticate
Thu May 12 03:29:16 2005 : Debug: rlm_eap_tls: processing TLS
Thu May 12 03:29:16 2005 : Info: rlm_eap_tls: Received EAP-TLS ACK message
Thu May 12 03:29:16 2005 : Debug: rlm_eap_tls: ack handshake fragment handler
Thu May 12 03:29:16 2005 : Debug: eaptls_verify returned 1
Thu May 12 03:29:16 2005 : Debug: eaptls_process returned 13
Thu May 12 03:29:16 2005 : Debug: modsingle[authenticate]: returned from eap (rlm_eap) for request 3
Thu May 12 03:29:16 2005 : Debug: modcall[authenticate]: module "eap" returns handled for request 3
Thu May 12 03:29:16 2005 : Debug: modcall: group authenticate returns handled for request 3
Sending Access-Challenge of id 47 to 141.24.44.109:1024
Service-Type == Login-User
EAP-Message = 0x012f001d158000000813cba9699297f528c177d516030100040e000000
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x4e687a566cd73b10ca58cb6b005ff420
Thu May 12 03:29:16 2005 : Debug: Finished request 3
Thu May 12 03:29:16 2005 : Debug: Going to the next request
Thu May 12 03:29:16 2005 : Debug: Waking up in 6 seconds...
rad_recv: Access-Request packet from host 141.24.44.109:1024, id=48, length=390
Framed-MTU = 1466
NAS-IP-Address = 10.0.1.1
NAS-Identifier = "ahzfnet AP1"
User-Name = "ahzf-intern"
Service-Type = Framed-User
NAS-Port = 256
NAS-Port-Type = Ethernet
NAS-Port-Id = "wl0"
Called-Station-Id = "00-11-24-06-2d-e1"
Calling-Station-Id = "00-0d-93-86-5f-aa"
Connect-Info = "CONNECT Ethernet 54Mbps Half duplex"
State = 0x4e687a566cd73b10ca58cb6b005ff420
EAP-Message = 0x022f00c41580000000ba1603010086100000820080c57b703ada04b581027ad54e6585fda31a6faec1d63b4ec36eeb19b0812ad346a
Message-Authenticator = 0xe1242dc129eb9b1cd4873b59d4e83672
Thu May 12 03:29:16 2005 : Debug: Processing the authorize section of radiusd.conf
Thu May 12 03:29:16 2005 : Debug: modcall: entering group authorize for request 4
Thu May 12 03:29:16 2005 : Debug: modsingle[authorize]: calling preprocess (rlm_preprocess) for request 4
Thu May 12 03:29:16 2005 : Debug: modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 4
Thu May 12 03:29:16 2005 : Debug: modcall[authorize]: module "preprocess" returns ok for request 4
Thu May 12 03:29:16 2005 : Debug: modsingle[authorize]: calling eap (rlm_eap) for request 4
Thu May 12 03:29:16 2005 : Debug: rlm_eap: EAP packet type response id 47 length 196
Thu May 12 03:29:16 2005 : Debug: rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
Thu May 12 03:29:16 2005 : Debug: modsingle[authorize]: returned from eap (rlm_eap) for request 4
Thu May 12 03:29:16 2005 : Debug: modcall[authorize]: module "eap" returns updated for request 4
Thu May 12 03:29:16 2005 : Debug: modsingle[authorize]: calling files (rlm_files) for request 4
Thu May 12 03:29:16 2005 : Debug: users: Matched entry DEFAULT at line 227
Thu May 12 03:29:16 2005 : Debug: modsingle[authorize]: returned from files (rlm_files) for request 4
Thu May 12 03:29:16 2005 : Debug: modcall[authorize]: module "files" returns ok for request 4
Thu May 12 03:29:16 2005 : Debug: modcall: group authorize returns updated for request 4
Thu May 12 03:29:16 2005 : Debug: rad_check_password: Found Auth-Type EAP
Thu May 12 03:29:16 2005 : Debug: auth: type "EAP"
Thu May 12 03:29:16 2005 : Debug: Processing the authenticate section of radiusd.conf
Thu May 12 03:29:16 2005 : Debug: modcall: entering group authenticate for request 4
Thu May 12 03:29:16 2005 : Debug: modsingle[authenticate]: calling eap (rlm_eap) for request 4
Thu May 12 03:29:16 2005 : Debug: rlm_eap: Request found, released from the list
Thu May 12 03:29:16 2005 : Debug: rlm_eap: EAP/ttls
Thu May 12 03:29:16 2005 : Debug: rlm_eap: processing type ttls
Thu May 12 03:29:16 2005 : Debug: rlm_eap_ttls: Authenticate
Thu May 12 03:29:16 2005 : Debug: rlm_eap_tls: processing TLS
Thu May 12 03:29:16 2005 : Info: rlm_eap_tls: Length Included
Thu May 12 03:29:16 2005 : Debug: eaptls_verify returned 11
Thu May 12 03:29:16 2005 : Debug: rlm_eap_tls: <<< TLS 1.0 Handshake [length 0086], ClientKeyExchange
Thu May 12 03:29:16 2005 : Info: TLS_accept: SSLv3 read client key exchange A
Thu May 12 03:29:16 2005 : Debug: rlm_eap_tls: <<< TLS 1.0 ChangeCipherSpec [length 0001]
Thu May 12 03:29:16 2005 : Debug: rlm_eap_tls: <<< TLS 1.0 Handshake [length 0010], Finished
Thu May 12 03:29:16 2005 : Info: TLS_accept: SSLv3 read finished A
Thu May 12 03:29:16 2005 : Debug: rlm_eap_tls: >>> TLS 1.0 ChangeCipherSpec [length 0001]
Thu May 12 03:29:16 2005 : Info: TLS_accept: SSLv3 write change cipher spec A
Thu May 12 03:29:16 2005 : Debug: rlm_eap_tls: >>> TLS 1.0 Handshake [length 0010], Finished
Thu May 12 03:29:16 2005 : Info: TLS_accept: SSLv3 write finished A
Thu May 12 03:29:16 2005 : Info: TLS_accept: SSLv3 flush data
Thu May 12 03:29:16 2005 : Info: (other): SSL negotiation finished successfully
Thu May 12 03:29:16 2005 : Debug: SSL Connection Established
Thu May 12 03:29:16 2005 : Debug: eaptls_process returned 13
Thu May 12 03:29:16 2005 : Debug: modsingle[authenticate]: returned from eap (rlm_eap) for request 4
Thu May 12 03:29:16 2005 : Debug: modcall[authenticate]: module "eap" returns handled for request 4
Thu May 12 03:29:16 2005 : Debug: modcall: group authenticate returns handled for request 4
Sending Access-Challenge of id 48 to 141.24.44.109:1024
Service-Type == Login-User
EAP-Message = 0x0130003915800000002f140301000101160301002432af8f32f5c58abe34f2055c3d486da2887391de681a9d480e72f5a114fd2eb82
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x25a34a4fb610938532799efb7a78019d
Thu May 12 03:29:16 2005 : Debug: Finished request 4
Thu May 12 03:29:16 2005 : Debug: Going to the next request
Thu May 12 03:29:16 2005 : Debug: Waking up in 6 seconds...
rad_recv: Access-Request packet from host 141.24.44.109:1024, id=49, length=265
Framed-MTU = 1466
NAS-IP-Address = 10.0.1.1
NAS-Identifier = "ahzfnet AP1"
User-Name = "ahzf-intern"
Service-Type = Framed-User
NAS-Port = 256
NAS-Port-Type = Ethernet
NAS-Port-Id = "wl0"
Called-Station-Id = "00-11-24-06-2d-e1"
Calling-Station-Id = "00-0d-93-86-5f-aa"
Connect-Info = "CONNECT Ethernet 54Mbps Half duplex"
State = 0x25a34a4fb610938532799efb7a78019d
EAP-Message = 0x0230004715800000003d17030100380cf0b134f54e87dce56e8d02dc3dc3e2a3b7ce91b2e3279b54f81d0e03eaa29d9d376db7badc1
Message-Authenticator = 0x84a0a9bfc4e57a26c8d833fb9fd1666b
Thu May 12 03:29:16 2005 : Debug: Processing the authorize section of radiusd.conf
Thu May 12 03:29:16 2005 : Debug: modcall: entering group authorize for request 5
Thu May 12 03:29:16 2005 : Debug: modsingle[authorize]: calling preprocess (rlm_preprocess) for request 5
Thu May 12 03:29:16 2005 : Debug: modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 5
Thu May 12 03:29:16 2005 : Debug: modcall[authorize]: module "preprocess" returns ok for request 5
Thu May 12 03:29:16 2005 : Debug: modsingle[authorize]: calling eap (rlm_eap) for request 5
Thu May 12 03:29:16 2005 : Debug: rlm_eap: EAP packet type response id 48 length 71
Thu May 12 03:29:16 2005 : Debug: rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
Thu May 12 03:29:16 2005 : Debug: modsingle[authorize]: returned from eap (rlm_eap) for request 5
Thu May 12 03:29:16 2005 : Debug: modcall[authorize]: module "eap" returns updated for request 5
Thu May 12 03:29:16 2005 : Debug: modsingle[authorize]: calling files (rlm_files) for request 5
Thu May 12 03:29:16 2005 : Debug: users: Matched entry DEFAULT at line 227
Thu May 12 03:29:16 2005 : Debug: modsingle[authorize]: returned from files (rlm_files) for request 5
Thu May 12 03:29:16 2005 : Debug: modcall[authorize]: module "files" returns ok for request 5
Thu May 12 03:29:16 2005 : Debug: modcall: group authorize returns updated for request 5
Thu May 12 03:29:16 2005 : Debug: rad_check_password: Found Auth-Type EAP
Thu May 12 03:29:16 2005 : Debug: auth: type "EAP"
Thu May 12 03:29:16 2005 : Debug: Processing the authenticate section of radiusd.conf
Thu May 12 03:29:16 2005 : Debug: modcall: entering group authenticate for request 5
Thu May 12 03:29:16 2005 : Debug: modsingle[authenticate]: calling eap (rlm_eap) for request 5
Thu May 12 03:29:16 2005 : Debug: rlm_eap: Request found, released from the list
Thu May 12 03:29:16 2005 : Debug: rlm_eap: EAP/ttls
Thu May 12 03:29:16 2005 : Debug: rlm_eap: processing type ttls
Thu May 12 03:29:16 2005 : Debug: rlm_eap_ttls: Authenticate
Thu May 12 03:29:16 2005 : Debug: rlm_eap_tls: processing TLS
Thu May 12 03:29:16 2005 : Info: rlm_eap_tls: Length Included
Thu May 12 03:29:16 2005 : Debug: eaptls_verify returned 11
Thu May 12 03:29:16 2005 : Debug: eaptls_process returned 7
Thu May 12 03:29:16 2005 : Debug: rlm_eap_ttls: Session established. Proceeding to decode tunneled attributes.
Thu May 12 03:29:16 2005 : Debug: Processing the authorize section of radiusd.conf
Thu May 12 03:29:16 2005 : Debug: modcall: entering group authorize for request 5
Thu May 12 03:29:16 2005 : Debug: modsingle[authorize]: calling preprocess (rlm_preprocess) for request 5
Thu May 12 03:29:16 2005 : Debug: modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 5
Thu May 12 03:29:16 2005 : Debug: modcall[authorize]: module "preprocess" returns ok for request 5
Thu May 12 03:29:16 2005 : Debug: modsingle[authorize]: calling eap (rlm_eap) for request 5
Thu May 12 03:29:16 2005 : Debug: rlm_eap: No EAP-Message, not doing EAP
Thu May 12 03:29:16 2005 : Debug: modsingle[authorize]: returned from eap (rlm_eap) for request 5
Thu May 12 03:29:16 2005 : Debug: modcall[authorize]: module "eap" returns noop for request 5
Thu May 12 03:29:16 2005 : Debug: modsingle[authorize]: calling files (rlm_files) for request 5
Thu May 12 03:29:16 2005 : Debug: users: Matched entry ahzf at line 94
Thu May 12 03:29:16 2005 : Debug: modsingle[authorize]: returned from files (rlm_files) for request 5
Thu May 12 03:29:16 2005 : Debug: modcall[authorize]: module "files" returns ok for request 5
Thu May 12 03:29:16 2005 : Debug: modcall: group authorize returns ok for request 5
Thu May 12 03:29:16 2005 : Debug: rad_check_password: Found Auth-Type Local
Thu May 12 03:29:16 2005 : Debug: auth: type Local
Thu May 12 03:29:16 2005 : Debug: auth: user supplied User-Password matches local User-Password
Thu May 12 03:29:16 2005 : Debug: TTLS: Got tunneled Access-Accept
Thu May 12 03:29:16 2005 : Debug: rlm_eap: Freeing handler
Thu May 12 03:29:16 2005 : Debug: modsingle[authenticate]: returned from eap (rlm_eap) for request 5
Thu May 12 03:29:16 2005 : Debug: modcall[authenticate]: module "eap" returns ok for request 5
Thu May 12 03:29:16 2005 : Debug: modcall: group authenticate returns ok for request 5
Sending Access-Accept of id 49 to 141.24.44.109:1024
Service-Type == Login-User
MS-MPPE-Recv-Key = 0x30ee88f4ff03ef2a96f446fa99fc6cfeab5e6c0a5c3a339816810aca715c3d83
MS-MPPE-Send-Key = 0x1a30e81dcac32a21e31015560cc58d677d14c619c7e1cbca62a8f84b289c6772
EAP-Message = 0x03300004
Message-Authenticator = 0x00000000000000000000000000000000
User-Name = "ahzf-intern"
Thu May 12 03:29:16 2005 : Debug: Finished request 5
Thu May 12 03:29:16 2005 : Debug: Going to the next request
Thu May 12 03:29:16 2005 : Debug: Waking up in 6 seconds...
thx... achim
- List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
