Hi Phil,
But i got from the ntlm_auth Error 691 which are send back to client.
Please post full debugging output i.e. run "radiusd -X" and post the output to the list.
Better yet, gather the debug output and READ IT carefully first, to see if you can spot the problem.
The MSCHAP password change code looks for the string "Password expired" in the output of the ntlm_auth command. If your ntlm_auth is printing something different, it'll just assume it's a regular failure.
Sure, here are the Debug output: FreeRADIUS Version 3.0.0, for host x86_64-portbld-freebsd9.0, built on Jun 12 2012 at 13:31:44 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 /usr/local/etc/raddb/radiusd.conf including configuration file /usr/local/etc/raddb/proxy.conf including configuration file /usr/local/etc/raddb/clients.conf including files in directory /usr/local/etc/raddb/mods-enabled/ including configuration file /usr/local/etc/raddb/mods-enabled/wimax including configuration file /usr/local/etc/raddb/mods-enabled/always including configuration file /usr/local/etc/raddb/mods-enabled/attr_filter including configuration file /usr/local/etc/raddb/mods-enabled/attr_rewrite including configuration file /usr/local/etc/raddb/mods-enabled/chap including configuration file /usr/local/etc/raddb/mods-enabled/checkval including configuration file /usr/local/etc/raddb/mods-enabled/counter including configuration file /usr/local/etc/raddb/mods-enabled/cui including configuration file /usr/local/etc/raddb/mods-enabled/detail including configuration file /usr/local/etc/raddb/mods-enabled/detail.log including configuration file /usr/local/etc/raddb/mods-enabled/digest including configuration file /usr/local/etc/raddb/mods-enabled/dynamic_clients including configuration file /usr/local/etc/raddb/mods-enabled/eap including configuration file /usr/local/etc/raddb/mods-enabled/echo including configuration file /usr/local/etc/raddb/mods-enabled/exec including configuration file /usr/local/etc/raddb/mods-enabled/expiration including configuration file /usr/local/etc/raddb/mods-enabled/expr including configuration file /usr/local/etc/raddb/mods-enabled/files including configuration file /usr/local/etc/raddb/mods-enabled/inner-eap including configuration file /usr/local/etc/raddb/mods-enabled/linelog including configuration file /usr/local/etc/raddb/mods-enabled/logintime including configuration file /usr/local/etc/raddb/mods-enabled/mschap including configuration file /usr/local/etc/raddb/mods-enabled/ntlm_auth including configuration file /usr/local/etc/raddb/mods-enabled/pap including configuration file /usr/local/etc/raddb/mods-enabled/passwd including configuration file /usr/local/etc/raddb/mods-enabled/preprocess including configuration file /usr/local/etc/raddb/mods-enabled/radutmp including configuration file /usr/local/etc/raddb/mods-enabled/realm including configuration file /usr/local/etc/raddb/mods-enabled/replicate including configuration file /usr/local/etc/raddb/mods-enabled/soh including configuration file /usr/local/etc/raddb/mods-enabled/sradutmp including configuration file /usr/local/etc/raddb/mods-enabled/unix including configuration file /usr/local/etc/raddb/mods-enabled/utf8 including configuration file /usr/local/etc/raddb/mods-enabled/acct_unique including configuration file /usr/local/etc/raddb/mods-enabled/ldap including configuration file /usr/local/etc/raddb/policy.conf including files in directory /usr/local/etc/raddb/sites-enabled/ including configuration file /usr/local/etc/raddb/sites-enabled/default including configuration file /usr/local/etc/raddb/sites-enabled/inner-tunnel main { security { allow_core_dumps = no } } including dictionary file /usr/local/etc/raddb/dictionary main { name = "radiusd" prefix = "/usr/local" localstatedir = "/var" sbindir = "/usr/local/sbin" logdir = "/var/log" run_dir = "/var/run/radiusd" libdir = "/usr/local/lib/freeradius-3.0.0" 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 = 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 = yes 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 coa { irt = 2 mrt = 16 mrc = 5 mrd = 30 } limit { max_connections = 16 max_requests = 0 lifetime = 0 idle_timeout = 0 } } 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 AP { ipaddr = 10.0.5.100 netmask = 32 require_message_authenticator = no secret = "**********" shortname = "AP" nastype = "other" } radiusd: #### Instantiating modules #### instantiate { Module: Linked to module rlm_exec Module: Instantiating module "exec" from file /usr/local/etc/raddb/mods-enabled/exec exec { wait = no input_pairs = "request" shell_escape = yes } Module: Linked to module rlm_expr Module: Instantiating module "expr" from file /usr/local/etc/raddb/mods-enabled/expr Module: Linked to module rlm_expiration Module: Instantiating module "expiration" from file /usr/local/etc/raddb/mods-enabled/expiration expiration { reply-message = "Password Has Expired " } Module: Linked to module rlm_logintime Module: Instantiating module "logintime" from file /usr/local/etc/raddb/mods-enabled/logintime logintime { reply-message = "You are calling outside your allowed timespan " minimum-timeout = 60 } } radiusd: #### Loading Virtual Servers #### server { # from file /usr/local/etc/raddb/radiusd.conf modules { Module: Creating Auth-Type = digest Module: Checking authenticate {...} for more modules to load Module: Linked to module rlm_pap Module: Instantiating module "pap" from file /usr/local/etc/raddb/mods-enabled/pap pap { encryption_scheme = "auto" auto_header = no } Module: Linked to module rlm_chap Module: Instantiating module "chap" from file /usr/local/etc/raddb/mods-enabled/chap Module: Linked to module rlm_mschap Module: Instantiating module "mschap" from file /usr/local/etc/raddb/mods-enabled/mschap mschap { use_mppe = no require_encryption = no require_strong = no with_ntdomain_hack = yes ntlm_auth = "/usr/local/bin/ntlm_auth --request-nt-key --username=%{%{Stripped-User-Name}:-%{%{User-Name}:-None}} --challenge=%{%{mschap:Challenge}:-00} --nt-response=%{%{mschap:NT-Response}:-00}" passchange { ntlm_auth = "/usr/local/bin/ntlm_auth --helper-protocol=ntlm-change-password-1" ntlm_auth_username = "username: %{mschap:User-Name}" ntlm_auth_domain = "nt-domain: %{mschap:NT-Domain}" } allow_retry = no retry_msg = "Re-enter (or reset) the password" } Module: Linked to module rlm_digest Module: Instantiating module "digest" from file /usr/local/etc/raddb/mods-enabled/digest Module: Linked to module rlm_unix Module: Instantiating module "unix" from file /usr/local/etc/raddb/mods-enabled/unix unix { radwtmp = "/var/log/radwtmp" } Module: Linked to module rlm_eap Module: Instantiating module "eap" from file /usr/local/etc/raddb/mods-enabled/eap eap { default_eap_type = "peap" timer_expire = 60 ignore_unknown_eap_types = no cisco_accounting_username_bug = no max_sessions = 4096 } Module: Linked to sub-module rlm_eap_md5 Module: Instantiating eap-md5 Module: Linked to sub-module rlm_eap_pwd Module: Instantiating eap-pwd pwd { group = 19 fragment_size = 1020 server_id = "theserver@example.com" virtual_server = "inner-tunnel" } 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 { tls = "tls-common" } tls-config tls-common { rsa_key_exchange = no dh_key_exchange = yes rsa_key_length = 512 dh_key_length = 512 verify_depth = 0 CA_path = "/usr/local/etc/raddb/certs" pem_file_type = yes private_key_file = "/usr/local/etc/raddb/certs/server.key" certificate_file = "/usr/local/etc/raddb/certs/server.pem" CA_file = "/usr/local/etc/raddb/certs/ca.pem" dh_file = "/usr/local/etc/raddb/certs/dh" random_file = "/usr/local/etc/raddb/certs/random" fragment_size = 1024 include_length = yes check_crl = no cipher_list = "DEFAULT" make_cert_command = "/usr/local/etc/raddb/certs/bootstrap" ecdh_curve = "prime256v1" cache { enable = yes lifetime = 8 max_entries = 255 } verify { } ocsp { enable = no override_cert_url = yes url = "http://127.0.0.1/ocsp/" use_nonce = yes timeout = 0 softfail = yes } } Module: Linked to sub-module rlm_eap_ttls Module: Instantiating eap-ttls ttls { tls = "tls-common" default_eap_type = "md5" copy_request_to_tunnel = no use_tunneled_reply = no virtual_server = "inner-tunnel" include_length = yes } debug: Using cached TLS configuration from previous invocation Module: Linked to sub-module rlm_eap_peap Module: Instantiating eap-peap peap { tls = "tls-common" default_eap_type = "mschapv2" copy_request_to_tunnel = no use_tunneled_reply = no proxy_tunneled_request_as_eap = yes virtual_server = "inner-tunnel" soh = no } debug: Using cached TLS configuration from previous invocation Module: Linked to sub-module rlm_eap_mschapv2 Module: Instantiating eap-mschapv2 mschapv2 { with_ntdomain_hack = no send_error = yes } Module: Checking authorize {...} for more modules to load Module: Linked to module rlm_preprocess Module: Instantiating module "preprocess" from file /usr/local/etc/raddb/mods-enabled/preprocess preprocess { huntgroups = "/usr/local/etc/raddb/huntgroups" hints = "/usr/local/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: Linked to module rlm_realm Module: Instantiating module "suffix" from file /usr/local/etc/raddb/mods-enabled/realm realm suffix { format = "suffix" delimiter = "@" ignore_default = no ignore_null = no } Module: Linked to module rlm_files Module: Instantiating module "files" from file /usr/local/etc/raddb/mods-enabled/files files { usersfile = "/usr/local/etc/raddb/users" acctusersfile = "/usr/local/etc/raddb/acct_users" preproxy_usersfile = "/usr/local/etc/raddb/preproxy_users" compat = "no" } Module: Checking preacct {...} for more modules to load Module: Loading virtual module acct_unique Module: Checking accounting {...} for more modules to load Module: Linked to module rlm_detail Module: Instantiating module "detail" from file /usr/local/etc/raddb/mods-enabled/detail detail { detailfile = "/var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d" header = "%t" detailperm = 384 dirperm = 493 locking = no log_packet_header = no } Module: Linked to module rlm_radutmp Module: Instantiating module "radutmp" from file /usr/local/etc/raddb/mods-enabled/radutmp radutmp { filename = "/var/log/radutmp" username = "%{User-Name}" case_sensitive = yes check_with_nas = yes perm = 384 callerid = yes } Module: Linked to module rlm_attr_filter Module: Instantiating module "attr_filter.accounting_response" from file /usr/local/etc/raddb/mods-enabled/attr_filter attr_filter attr_filter.accounting_response { attrsfile = "/usr/local/etc/raddb/attrs.accounting_response" key = "%{User-Name}" relaxed = no } 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 Module: Loading virtual module remove_reply_message_if_eap Module: Linked to module rlm_always Module: Instantiating module "noop" from file /usr/local/etc/raddb/mods-enabled/always always noop { rcode = "noop" simulcount = 0 mpp = no } Module: Instantiating module "attr_filter.access_reject" from file /usr/local/etc/raddb/mods-enabled/attr_filter attr_filter attr_filter.access_reject { attrsfile = "/usr/local/etc/raddb/attrs.access_reject" key = "%{User-Name}" relaxed = no } Module: Loading virtual module remove_reply_message_if_eap } # modules } # server server inner-tunnel { # from file /usr/local/etc/raddb/sites-enabled/inner-tunnel modules { Module: Checking authenticate {...} for more modules to load Module: Checking authorize {...} for more modules to load 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 max_pps = 0 } listen { type = "acct" ipaddr = * port = 0 max_pps = 0 } listen { type = "auth" ipaddr = 127.0.0.1 port = 18120 max_pps = 0 } Listening on authentication address * port 1812 Listening on accounting address * port 1813 Listening on authentication address 127.0.0.1 port 18120 as server inner-tunnel Opening new proxy address * port 1814 Listening on proxy address * port 1814 Ready to process requests. rad_recv: Access-Request packet from host 10.0.5.100 port 32783, id=106, length=359 Acct-Multi-Session-Id = "00-A1-B1-4D-D4-78-A1-23-DF-79-F0-B9-4F-D7-38-03-00-0D-86-CF" Acct-Session-Id = "1d01db22-000000ea" NAS-Port = 218 NAS-Port-Type = Wireless-802.11 NAS-Identifier = "AccessPoint1" NAS-IP-Address = 10.0.1.50 Framed-MTU = 1496 User-Name = "TEST\\user1" Calling-Station-Id = "A1-23-DF-79-F0-B9" Called-Station-Id = "00-A1-B1-4D-D4-78" Service-Type = Framed-User EAP-Message = 0x02750015015a4f4f504c55535c6173646631323334 Attr-26 = 0x00002228000c737369643d7a706c5f320016696e636f6d696e672d766c616e2d69643d313238000f67726f75703d4dfc6e6368656e00127673632d756e697175652d69643d31300017706879747970653d49454545383032646f74313167 Attr-26.8744.250 = 0x00000003 Attr-26.8744.249 = 0xc0a81489 Message-Authenticator = 0xe153ae3481cd9424c23bf36b5f175aaf (0) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default (0) group authorize { (0) - entering group authorize {...} (0) [preprocess] = ok (0) [chap] = noop (0) [mschap] = noop (0) [digest] = noop (0) suffix : No '@' in User-Name = "TEST\user1", looking up realm NULL (0) suffix : No such realm "NULL" (0) [suffix] = noop (0) eap : EAP packet type response id 117 length 21 (0) eap : EAP-Identity reply, returning 'ok' so we can short-circuit the rest of authorize (0) [eap] = ok (0) Found Auth-Type = EAP (0) # Executing group from file /usr/local/etc/raddb/sites-enabled/default (0) group authenticate { (0) - entering group authenticate {...} (0) eap : EAP Identity (0) eap : processing type peap (0) peap : Flushing SSL sessions (of #0) (0) peap : Initiate (0) peap : Start returned 1 (0) [eap] = handled Sending Access-Challenge of id 106 to 10.0.5.100 port 32783 EAP-Message = 0x017600061920 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x233fc17e2349d8f3e83a34544ff58a3c (0) Finished request 0. Waking up in 0.3 seconds. rad_recv: Access-Request packet from host 10.0.5.100 port 32783, id=226, length=486 Acct-Multi-Session-Id = "00-A1-B1-4D-D4-78-A1-23-DF-79-F0-B9-4F-D7-38-03-00-0D-86-CF" Acct-Session-Id = "1d01db22-000000ea" NAS-Port = 218 NAS-Port-Type = Wireless-802.11 NAS-Identifier = "AccessPoint1" NAS-IP-Address = 10.0.1.50 Framed-MTU = 1496 User-Name = "TEST\\user1" Calling-Station-Id = "A1-23-DF-79-F0-B9" Called-Station-Id = "00-A1-B1-4D-D4-78" Service-Type = Framed-User EAP-Message = 0x0276008219800000007816030100730100006f03014fd73824002ede6455fb6910c0084294967e65e18410e16d52d9926c80e67e5e000018002f00350005000ac013c014c009c00a00320038001300040100002eff010001000000001500130000107a6f6f706c75735c6173646631323334000a0006000400170018000b00020100 State = 0x233fc17e2349d8f3e83a34544ff58a3c Attr-26 = 0x00002228000c737369643d7a706c5f320016696e636f6d696e672d766c616e2d69643d313238000f67726f75703d4dfc6e6368656e00127673632d756e697175652d69643d31300017706879747970653d49454545383032646f74313167 Attr-26.8744.250 = 0x00000003 Attr-26.8744.249 = 0xc0a81489 Message-Authenticator = 0xc113cc579b9a44ae6f78cc78df61fe45 (1) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default (1) group authorize { (1) - entering group authorize {...} (1) [preprocess] = ok (1) [chap] = noop (1) [mschap] = noop (1) [digest] = noop (1) suffix : No '@' in User-Name = "TEST\user1", looking up realm NULL (1) suffix : No such realm "NULL" (1) [suffix] = noop (1) eap : EAP packet type response id 118 length 130 (1) eap : Continuing tunnel setup. (1) [eap] = ok (1) Found Auth-Type = EAP (1) # Executing group from file /usr/local/etc/raddb/sites-enabled/default (1) group authenticate { (1) - entering group authenticate {...} (1) eap : Request found, released from the list (1) eap : EAP/peap (1) eap : processing type peap (1) peap : processing EAP-TLS TLS Length 120 (1) peap : Length Included (1) peap : eaptls_verify returned 11 (1) peap : (other): before/accept initialization (1) peap : TLS_accept: before/accept initialization (1) peap : <<< TLS 1.0 Handshake [length 0073], ClientHello (1) peap : TLS_accept: SSLv3 read client hello A (1) peap : >>> TLS 1.0 Handshake [length 0051], ServerHello (1) peap : TLS_accept: SSLv3 write server hello A (1) peap : >>> TLS 1.0 Handshake [length 0cc5], Certificate (1) peap : TLS_accept: SSLv3 write certificate A (1) peap : >>> TLS 1.0 Handshake [length 0004], ServerHelloDone (1) peap : TLS_accept: SSLv3 write server done A (1) peap : TLS_accept: SSLv3 flush data (1) peap : TLS_accept: Need to read more data: SSLv3 read client certificate A In SSL Handshake Phase In SSL Accept mode (1) peap : eaptls_process returned 13 (1) peap : FR_TLS_HANDLED (1) [eap] = handled Sending Access-Challenge of id 226 to 10.0.5.100 port 32783 EAP-Message = 0x017703ec19c000000d2916030100510200004d03014fd73898ff528088986ce611991705eb5a5f001acf69d93b17f1a9fa7cab3d0e20f3ed404d9531a40bbcad0cadbad4133c4ad48296899ea27022fc32535d459cf0002f000005ff010001001603010cc50b000cc1000cbe0007aa308207a63082068ea003020102020310004e300d06092a864886f70d01010405003081a3310b30090603550406130244453111300f06035504081308426176617269616e310f300d060355040713064d756e69636831133011060355040a130a5a6f6f706c757320414731193017060355040b1310495420496e667261737472756b747572311e301c0603550403 EAP-Message = 0x1315777777706b692e7765622e7a6f6f706c75732e64653120301e06092a864886f70d010901161173797361646d407a6f6f706c75732e6465301e170d3132303232383039323934315a170d3135303232383039323934315a3081c3310b30090603550406130244453111300f06035504081308426176617269616e310f300d060355040713064d756e69636831133011060355040a130a5a6f6f706c757320414731293027060355040a13206639323232396139633932306238656464613063346563383830643865383362310b3009060355040b130249543121301f060355040313187a7072616469757330312e7a6f6f706c75732e6c6f63616c EAP-Message = 0x3120301e06092a864886f70d010901161173797361646d407a6f6f706c75732e646530820222300d06092a864886f70d01010105000382020f003082020a0282020100df0e40f450e8633fdc375cb76ddca4885ce8cb275601f5b5e78a0ff8f4e8f13036c27a4e3c2e503e005d11e5c19a8b535e68a015b67f15b313d88a21df7b788ce45174c0137beadfb8186928e9acc169237805e0a00ea8f8245c7d4b1d64214e368339fe807dab5cc82c235823474903f76d8e363ff25a79094959af1edf13d4b23c4f9942467ffd088f91fd7072618e9e95d6360e44ede071785ce41f0899d4abe3e8d941f728ad204ad1e48f1fd12384ab392ed048d917b361 EAP-Message = 0x77efb35d76edcf6f6bf4518c46e53186e9c8ca7560481f8a87eb9cba46f56716fcff6a05ae25a1917ca1ede18c05640b41242465118dc66de1f3f22aa77598df0f0130070b95af02502eb9dd86f087502a2ce4ddf67dc94ccb60edba0f4e92e5f9ca75e950bc89a21671430395782d6d8fb78ba77b497ab6577e673acd4b9ebda8eb638d2aa6ba89798d0adc603a765c7b109f7b204abab14831b08fe1b34be34f3e1acb92bf878644e94f5de7381e3df2647f307d9343332112b978d68b02c63658d617268e610bf337d85f0a62a2e1a7b5a8fa1261e1835101920e3b37fd4e95e3fead50a5cac3239e57541679679824eacd1aa6 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x233fc17e2248d8f3e83a34544ff58a3c (1) Finished request 1. Waking up in 0.3 seconds. rad_recv: Access-Request packet from host 10.0.5.100 port 32783, id=207, length=362 Acct-Multi-Session-Id = "00-A1-B1-4D-D4-78-A1-23-DF-79-F0-B9-4F-D7-38-03-00-0D-86-CF" Acct-Session-Id = "1d01db22-000000ea" NAS-Port = 218 NAS-Port-Type = Wireless-802.11 NAS-Identifier = "AccessPoint1" NAS-IP-Address = 10.0.1.50 Framed-MTU = 1496 User-Name = "TEST\\user1" Calling-Station-Id = "A1-23-DF-79-F0-B9" Called-Station-Id = "00-A1-B1-4D-D4-78" Service-Type = Framed-User EAP-Message = 0x027700061900 State = 0x233fc17e2248d8f3e83a34544ff58a3c Attr-26 = 0x00002228000c737369643d7a706c5f320016696e636f6d696e672d766c616e2d69643d313238000f67726f75703d4dfc6e6368656e00127673632d756e697175652d69643d31300017706879747970653d49454545383032646f74313167 Attr-26.8744.250 = 0x00000003 Attr-26.8744.249 = 0xc0a81489 Message-Authenticator = 0x09aba499b093fc17f1b1ad231435c1dd (2) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default (2) group authorize { (2) - entering group authorize {...} (2) [preprocess] = ok (2) [chap] = noop (2) [mschap] = noop (2) [digest] = noop (2) suffix : No '@' in User-Name = "TEST\user1", looking up realm NULL (2) suffix : No such realm "NULL" (2) [suffix] = noop (2) eap : EAP packet type response id 119 length 6 (2) eap : Continuing tunnel setup. (2) [eap] = ok (2) Found Auth-Type = EAP (2) # Executing group from file /usr/local/etc/raddb/sites-enabled/default (2) group authenticate { (2) - entering group authenticate {...} (2) eap : Request found, released from the list (2) eap : EAP/peap (2) eap : processing type peap (2) peap : processing EAP-TLS (2) peap : Received TLS ACK (2) peap : Received TLS ACK (2) peap : ACK handshake fragment handler (2) peap : eaptls_verify returned 1 (2) peap : eaptls_process returned 13 (2) peap : FR_TLS_HANDLED (2) [eap] = handled Sending Access-Challenge of id 207 to 10.0.5.100 port 32783 EAP-Message = 0x017803e81940766385383e2cde4857beed6f5d0055147b933e7daa9922162c79d246e82182b9093f71aa15acaac374d5e514c545fde8d4246e4471d9ead260e06fc5a292a62aac5911d4b904b8015bf168d6c7022f8b8b0203010001a38202bf308202bb300c0603551d130101ff04023000300e0603551d0f0101ff0404030205a0301406096086480186f84201010101ff04040302064030160603551d250101ff040c300a06082b06010505070301301d0603551d0e0416041424e274626b9d850eb8eb9fd2a5d4e4555dccc3233081d80603551d230481d03081cd8014343094169c0bc40653b5ebaf41601f3b65d91227a181a9a481a63081a331 EAP-Message = 0x0b30090603550406130244453111300f06035504081308426176617269616e310f300d060355040713064d756e69636831133011060355040a130a5a6f6f706c757320414731193017060355040b1310495420496e667261737472756b747572311e301c06035504031315777777706b692e7765622e7a6f6f706c75732e64653120301e06092a864886f70d010901161173797361646d407a6f6f706c75732e64658209008f68987367f3a4b330360603551d11042f302d82187a7072616469757330312e7a6f6f706c75732e6c6f63616c811173797361646d407a6f6f706c75732e6465301c0603551d1204153013811173797361646d407a6f6f70 EAP-Message = 0x6c75732e6465304a0603551d1f04433041303fa03da03b8639687474703a2f2f777777706b692e7765622e7a6f6f706c75732e64652f7068706b692f696e6465782e7068703f73746167653d646c5f63726c303906096086480186f842010d042c162a5048506b692f4f70656e53534c2047656e65726174656420536572766572204365727469666963617465303206096086480186f842010204251623687474703a2f2f777777706b692e7765622e7a6f6f706c75732e64652f7068706b692f302306096086480186f8420103041616146e735f7265766f6b655f71756572792e7068703f303d06096086480186f84201080430162e687474703a2f EAP-Message = 0x2f777777706b692e7765622e7a6f6f706c75732e64652f7068706b692f706f6c6963792e68746d6c300d06092a864886f70d01010405000382010100a9926e3eab9f9ed846e4d3618ab5df744295922b7393517c86a7e9e879ae6862200092525a365845841ed019acb8401c12057b4fd132a39fdb89eed85e85beb4ec203049f8dfd9c3038bee65de5bb59962b0a77e9a4d95b99340ed94d38845b185f1483898f18272d216f4d831bfe43f02df131b8445b7417677965db6f94676b0c7337240f09fbd8fd5755e0c0fe88469f12a0b4b929dcd4327517f0cdc4327432be87207cf40f81f60d90c16d7045566b611ee90 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x233fc17e2147d8f3e83a34544ff58a3c (2) Finished request 2. Waking up in 0.3 seconds. rad_recv: Access-Request packet from host 10.0.5.100 port 32783, id=156, length=362 Acct-Multi-Session-Id = "00-A1-B1-4D-D4-78-A1-23-DF-79-F0-B9-4F-D7-38-03-00-0D-86-CF" Acct-Session-Id = "1d01db22-000000ea" NAS-Port = 218 NAS-Port-Type = Wireless-802.11 NAS-Identifier = "AccessPoint1" NAS-IP-Address = 10.0.1.50 Framed-MTU = 1496 User-Name = "TEST\\user1" Calling-Station-Id = "A1-23-DF-79-F0-B9" Called-Station-Id = "00-A1-B1-4D-D4-78" Service-Type = Framed-User EAP-Message = 0x027800061900 State = 0x233fc17e2147d8f3e83a34544ff58a3c Attr-26 = 0x00002228000c737369643d7a706c5f320016696e636f6d696e672d766c616e2d69643d313238000f67726f75703d4dfc6e6368656e00127673632d756e697175652d69643d31300017706879747970653d49454545383032646f74313167 Attr-26.8744.250 = 0x00000003 Attr-26.8744.249 = 0xc0a81489 Message-Authenticator = 0x46ddf4fb8e62864d34ee09b02240cac4 (3) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default (3) group authorize { (3) - entering group authorize {...} (3) [preprocess] = ok (3) [chap] = noop (3) [mschap] = noop (3) [digest] = noop (3) suffix : No '@' in User-Name = "TEST\user1", looking up realm NULL (3) suffix : No such realm "NULL" (3) [suffix] = noop (3) eap : EAP packet type response id 120 length 6 (3) eap : Continuing tunnel setup. (3) [eap] = ok (3) Found Auth-Type = EAP (3) # Executing group from file /usr/local/etc/raddb/sites-enabled/default (3) group authenticate { (3) - entering group authenticate {...} (3) eap : Request found, released from the list (3) eap : EAP/peap (3) eap : processing type peap (3) peap : processing EAP-TLS (3) peap : Received TLS ACK (3) peap : Received TLS ACK (3) peap : ACK handshake fragment handler (3) peap : eaptls_verify returned 1 (3) peap : eaptls_process returned 13 (3) peap : FR_TLS_HANDLED (3) [eap] = handled Sending Access-Challenge of id 156 to 10.0.5.100 port 32783 EAP-Message = 0x017903e81940dd918bae3094651e2d38da6cb6470e5a5705d04419ecc02984c06dd99d858684b4ffeea1f0049440d3542eb307f94b4e343a78ad2bf5d8dff067c49eed40825295fc525c89ffe00316ab9800050e3082050a308203f2a0030201020209008f68987367f3a4b3300d06092a864886f70d01010405003081a3310b30090603550406130244453111300f06035504081308426176617269616e310f300d060355040713064d756e69636831133011060355040a130a5a6f6f706c757320414731193017060355040b1310495420496e667261737472756b747572311e301c06035504031315777777706b692e7765622e7a6f6f706c75732e EAP-Message = 0x64653120301e06092a864886f70d010901161173797361646d407a6f6f706c75732e6465301e170d3039303331333134323030315a170d3134303331333134323030315a3081a3310b30090603550406130244453111300f06035504081308426176617269616e310f300d060355040713064d756e69636831133011060355040a130a5a6f6f706c757320414731193017060355040b1310495420496e667261737472756b747572311e301c06035504031315777777706b692e7765622e7a6f6f706c75732e64653120301e06092a864886f70d010901161173797361646d407a6f6f706c75732e646530820122300d06092a864886f70d0101010500 EAP-Message = 0x0382010f003082010a0282010100b53247f132a0563881dd2cd39b014fce9dd553316e5acfad692af9121c4144dd5518fddd97459ae4c5b58dde04746615af13ce199e492269694b7a90f39a0ee2abb1222fc5b966b75f04e7d5b3ea9855bea211c5fbbfcb8f9d9059034e2af246494ba7d21812bce51f716000309a2842a43b53b3d69ded50954cf1bf0259e32410074bdd61676dac3af823013cc07fecd18329dee9a0129ae38fe37db7cf2161b1a6a313a2e48f07c80a630467dae941cfa094df8eebd542b85275f6dc776d6eb96f28b879c1f3178fcae1c8c984e8aaec01cd18c3ccdf90a9fea7a1239b605bc2c3a4092dc2551e84007d9a047359 EAP-Message = 0xf47dda3aba5d94d2785f684b8bd95603410203010001a382013d30820139300c0603551d13040530030101ff300b0603551d0f040403020106301106096086480186f8420101040403020007301d0603551d0e04160414343094169c0bc40653b5ebaf41601f3b65d91227301c0603551d1104153013811173797361646d407a6f6f706c75732e6465304a0603551d1f04433041303fa03da03b8639687474703a2f2f777777706b692e7765622e7a6f6f706c75732e64652f7068706b692f696e6465782e7068703f73746167653d646c5f63726c304106096086480186f842010d043416325048506b692f4f70656e53 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x233fc17e2046d8f3e83a34544ff58a3c (3) Finished request 3. Waking up in 0.2 seconds. rad_recv: Access-Request packet from host 10.0.5.100 port 32783, id=11, length=362 Acct-Multi-Session-Id = "00-A1-B1-4D-D4-78-A1-23-DF-79-F0-B9-4F-D7-38-03-00-0D-86-CF" Acct-Session-Id = "1d01db22-000000ea" NAS-Port = 218 NAS-Port-Type = Wireless-802.11 NAS-Identifier = "AccessPoint1" NAS-IP-Address = 10.0.1.50 Framed-MTU = 1496 User-Name = "TEST\\user1" Calling-Station-Id = "A1-23-DF-79-F0-B9" Called-Station-Id = "00-A1-B1-4D-D4-78" Service-Type = Framed-User EAP-Message = 0x027900061900 State = 0x233fc17e2046d8f3e83a34544ff58a3c Attr-26 = 0x00002228000c737369643d7a706c5f320016696e636f6d696e672d766c616e2d69643d313238000f67726f75703d4dfc6e6368656e00127673632d756e697175652d69643d31300017706879747970653d49454545383032646f74313167 Attr-26.8744.250 = 0x00000003 Attr-26.8744.249 = 0xc0a81489 Message-Authenticator = 0xec85e36dffa4447885ebfa7cfdb60897 (4) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default (4) group authorize { (4) - entering group authorize {...} (4) [preprocess] = ok (4) [chap] = noop (4) [mschap] = noop (4) [digest] = noop (4) suffix : No '@' in User-Name = "TEST\user1", looking up realm NULL (4) suffix : No such realm "NULL" (4) [suffix] = noop (4) eap : EAP packet type response id 121 length 6 (4) eap : Continuing tunnel setup. (4) [eap] = ok (4) Found Auth-Type = EAP (4) # Executing group from file /usr/local/etc/raddb/sites-enabled/default (4) group authenticate { (4) - entering group authenticate {...} (4) eap : Request found, released from the list (4) eap : EAP/peap (4) eap : processing type peap (4) peap : processing EAP-TLS (4) peap : Received TLS ACK (4) peap : Received TLS ACK (4) peap : ACK handshake fragment handler (4) peap : eaptls_verify returned 1 (4) peap : eaptls_process returned 13 (4) peap : FR_TLS_HANDLED (4) [eap] = handled Sending Access-Challenge of id 11 to 10.0.5.100 port 32783 EAP-Message = 0x017a01891900534c2047656e65726174656420526f6f7420436572746966696361746520417574686f72697479303d06096086480186f84201080430162e687474703a2f2f777777706b692e7765622e7a6f6f706c75732e64652f7068706b692f706f6c6963792e68746d6c300d06092a864886f70d010104050003820101009ebc1a5dd90c801d205cb2a90c8bc3ab00db1ecb7d733632e6c5cfc033ded56fe93dc9752096ea56f194ebc980b843d7b1444b46689baea6c180997eaa77ae4b5aed2657c924a0f160b64adeef2af57df3ea220a94dd1c6571213f432e0888abc037f9ad970406d797bce1163d31c9df848258296d336f929dadd33ba7 EAP-Message = 0xad9e6bd0a8e101e4514e569f64097e12bb6e05ae9e51a4170b056570bd14a33faa584075a9dfafa8dd979d4664f76f5730953903ce77c7b4e8e2e3356ed9be221fd6f872dab6451da6950f46893af28efb6df277e22169e81884cd3abe4c464523d7622dfe93d1a5f29b2d623292eca09b3bfe84fb67b6d4749ff6b61de2971388045316030100040e000000 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x233fc17e2745d8f3e83a34544ff58a3c (4) Finished request 4. Waking up in 0.2 seconds. rad_recv: Access-Request packet from host 10.0.5.100 port 32783, id=248, length=952 Acct-Multi-Session-Id = "00-A1-B1-4D-D4-78-A1-23-DF-79-F0-B9-4F-D7-38-03-00-0D-86-CF" Acct-Session-Id = "1d01db22-000000ea" NAS-Port = 218 NAS-Port-Type = Wireless-802.11 NAS-Identifier = "AccessPoint1" NAS-IP-Address = 10.0.1.50 Framed-MTU = 1496 User-Name = "TEST\\user1" Calling-Station-Id = "A1-23-DF-79-F0-B9" Called-Station-Id = "00-A1-B1-4D-D4-78" Service-Type = Framed-User EAP-Message = 0x027a02501980000002461603010206100002020200acca8ade0f1fd58406607d426b60e70361405ebf04154b58b5e1d1a8389c062ca456d04c9774825a8758dea005093c8bc80926b15d45e95a23b1481627470e61f7c0ef7f76ad0f93dd48d7835f5f2a362dca360d8c98a50e40f928366a67d71d740a4840f7123a5c68ef91b870b60867a0231378d22c106f6f744631722ea7dce899d39f1781eb1dcb6f1ce8ded9303f276929c073691f32271ffd931e351170f37e3dcf441d3deabc91c6d98680f713694b8d99a360a7eeeb7db12f862c6e97d7d850cce98662d4635f6e231433e11abf8bac7139653682960981c85881a10a52570aa8ed0c0af6 EAP-Message = 0xe9bcf38e1699dc72aeb83b0d9c364511450e5ea5bb4f3eabf3461249af95b2adeddaf4feb70036f8f211f65b26caf7719100a035b64e9ef74dcb0831a724d41376aaab060eae667952bdbbc6e70f3908305e9351b9f23d9e9012aa7aeed7f0e35da736fb1b587d8dc0df9f7c490c4539fc95bdb28fc39fbe965700a18cba4b216b95ae74a170aff5cb7ad7ba8f2a95e542e53027d8bc1fe12894fc7519952633fef32543972883e7a66d8a6464d3a39f66631aebba43104d2976128a39b49c1b46a4fec4a48dd56b5e225414a83ebc2efc8742a5e99cbf9b12804c6680aebe25da8104c7996ae77f7e849b8f35febd7c52d8fd894ca5cd6423ac144771 EAP-Message = 0xcee2b19e48cfb074a1da7322d2afc1a62768444cb53ecb9a13dedc1403010001011603010030641a65b0a9a884ed3878189b2f7bbd64b715575e1d9895118cbd778b57b163d03c93e0a0f7f3e2133cbae51da4f73a55 State = 0x233fc17e2745d8f3e83a34544ff58a3c Attr-26 = 0x00002228000c737369643d7a706c5f320016696e636f6d696e672d766c616e2d69643d313238000f67726f75703d4dfc6e6368656e00127673632d756e697175652d69643d31300017706879747970653d49454545383032646f74313167 Attr-26.8744.250 = 0x00000003 Attr-26.8744.249 = 0xc0a81489 Message-Authenticator = 0xc9e0e7727d36281e317a5814ab7e34b0 (5) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default (5) group authorize { (5) - entering group authorize {...} (5) [preprocess] = ok (5) [chap] = noop (5) [mschap] = noop (5) [digest] = noop (5) suffix : No '@' in User-Name = "TEST\user1", looking up realm NULL (5) suffix : No such realm "NULL" (5) [suffix] = noop (5) eap : EAP packet type response id 122 length 253 (5) eap : Continuing tunnel setup. (5) [eap] = ok (5) Found Auth-Type = EAP (5) # Executing group from file /usr/local/etc/raddb/sites-enabled/default (5) group authenticate { (5) - entering group authenticate {...} (5) eap : Request found, released from the list (5) eap : EAP/peap (5) eap : processing type peap (5) peap : processing EAP-TLS TLS Length 582 (5) peap : Length Included (5) peap : eaptls_verify returned 11 (5) peap : <<< TLS 1.0 Handshake [length 0206], ClientKeyExchange (5) peap : TLS_accept: SSLv3 read client key exchange A (5) peap : <<< TLS 1.0 ChangeCipherSpec [length 0001] (5) peap : <<< TLS 1.0 Handshake [length 0010], Finished (5) peap : TLS_accept: SSLv3 read finished A (5) peap : >>> TLS 1.0 ChangeCipherSpec [length 0001] (5) peap : TLS_accept: SSLv3 write change cipher spec A (5) peap : >>> TLS 1.0 Handshake [length 0010], Finished (5) peap : TLS_accept: SSLv3 write finished A (5) peap : TLS_accept: SSLv3 flush data SSL: adding session f3ed404d9531a40bbcad0cadbad4133c4ad48296899ea27022fc32535d459cf0 to cache (5) peap : (other): SSL negotiation finished successfully SSL Connection Established (5) peap : eaptls_process returned 13 (5) peap : FR_TLS_HANDLED (5) [eap] = handled Sending Access-Challenge of id 248 to 10.0.5.100 port 32783 EAP-Message = 0x017b004119001403010001011603010030142a567a85a52fa32a1ccb3cabd673369805c95546236721bc294226ffb35a1b72a92cc5dacf5be8944ff2f5faf613e4 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x233fc17e2644d8f3e83a34544ff58a3c (5) Finished request 5. Waking up in 0.2 seconds. rad_recv: Access-Request packet from host 10.0.5.100 port 32783, id=236, length=362 Acct-Multi-Session-Id = "00-A1-B1-4D-D4-78-A1-23-DF-79-F0-B9-4F-D7-38-03-00-0D-86-CF" Acct-Session-Id = "1d01db22-000000ea" NAS-Port = 218 NAS-Port-Type = Wireless-802.11 NAS-Identifier = "AccessPoint1" NAS-IP-Address = 10.0.1.50 Framed-MTU = 1496 User-Name = "TEST\\user1" Calling-Station-Id = "A1-23-DF-79-F0-B9" Called-Station-Id = "00-A1-B1-4D-D4-78" Service-Type = Framed-User EAP-Message = 0x027b00061900 State = 0x233fc17e2644d8f3e83a34544ff58a3c Attr-26 = 0x00002228000c737369643d7a706c5f320016696e636f6d696e672d766c616e2d69643d313238000f67726f75703d4dfc6e6368656e00127673632d756e697175652d69643d31300017706879747970653d49454545383032646f74313167 Attr-26.8744.250 = 0x00000003 Attr-26.8744.249 = 0xc0a81489 Message-Authenticator = 0x110a13403df450de92653db8bdea68cf (6) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default (6) group authorize { (6) - entering group authorize {...} (6) [preprocess] = ok (6) [chap] = noop (6) [mschap] = noop (6) [digest] = noop (6) suffix : No '@' in User-Name = "TEST\user1", looking up realm NULL (6) suffix : No such realm "NULL" (6) [suffix] = noop (6) eap : EAP packet type response id 123 length 6 (6) eap : Continuing tunnel setup. (6) [eap] = ok (6) Found Auth-Type = EAP (6) # Executing group from file /usr/local/etc/raddb/sites-enabled/default (6) group authenticate { (6) - entering group authenticate {...} (6) eap : Request found, released from the list (6) eap : EAP/peap (6) eap : processing type peap (6) peap : processing EAP-TLS (6) peap : Received TLS ACK (6) peap : Received TLS ACK (6) peap : ACK handshake is finished (6) peap : eaptls_verify returned 3 (6) peap : eaptls_process returned 3 (6) peap : FR_TLS_SUCCESS (6) peap : Session established. Decoding tunneled attributes. (6) peap : Peap state TUNNEL ESTABLISHED (6) [eap] = handled Sending Access-Challenge of id 236 to 10.0.5.100 port 32783 EAP-Message = 0x017c002b190017030100209d8662246db6c2b5ce090091cd7608392fa5e1865ac698f0d2d8955cc3f6a56b Message-Authenticator = 0x00000000000000000000000000000000 State = 0x233fc17e2543d8f3e83a34544ff58a3c (6) Finished request 6. Waking up in 0.1 seconds. rad_recv: Access-Request packet from host 10.0.5.100 port 32783, id=36, length=415 Acct-Multi-Session-Id = "00-A1-B1-4D-D4-78-A1-23-DF-79-F0-B9-4F-D7-38-03-00-0D-86-CF" Acct-Session-Id = "1d01db22-000000ea" NAS-Port = 218 NAS-Port-Type = Wireless-802.11 NAS-Identifier = "AccessPoint1" NAS-IP-Address = 10.0.1.50 Framed-MTU = 1496 User-Name = "TEST\\user1" Calling-Station-Id = "A1-23-DF-79-F0-B9" Called-Station-Id = "00-A1-B1-4D-D4-78" Service-Type = Framed-User EAP-Message = 0x027c003b1900170301003088024a1842d558d7174d7b2bb36ef45d3b11f4e252f68af7c7d1a216e2ebf6b5a3e0adb89bd232b6f8f297e69d26256e State = 0x233fc17e2543d8f3e83a34544ff58a3c Attr-26 = 0x00002228000c737369643d7a706c5f320016696e636f6d696e672d766c616e2d69643d313238000f67726f75703d4dfc6e6368656e00127673632d756e697175652d69643d31300017706879747970653d49454545383032646f74313167 Attr-26.8744.250 = 0x00000003 Attr-26.8744.249 = 0xc0a81489 Message-Authenticator = 0x6ea6ff20fdce1b56c97c6ac976f3223d (7) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default (7) group authorize { (7) - entering group authorize {...} (7) [preprocess] = ok (7) [chap] = noop (7) [mschap] = noop (7) [digest] = noop (7) suffix : No '@' in User-Name = "TEST\user1", looking up realm NULL (7) suffix : No such realm "NULL" (7) [suffix] = noop (7) eap : EAP packet type response id 124 length 59 (7) eap : Continuing tunnel setup. (7) [eap] = ok (7) Found Auth-Type = EAP (7) # Executing group from file /usr/local/etc/raddb/sites-enabled/default (7) group authenticate { (7) - entering group authenticate {...} (7) eap : Request found, released from the list (7) eap : EAP/peap (7) eap : processing type peap (7) peap : processing EAP-TLS (7) peap : eaptls_verify returned 7 (7) peap : Done initial handshake (7) peap : eaptls_process returned 7 (7) peap : FR_TLS_OK (7) peap : Session established. Decoding tunneled attributes. (7) peap : Peap state WAITING FOR INNER IDENTITY (7) peap : Identity - TEST\user1 (7) peap : Got inner identity 'TEST\user1' (7) peap : Setting default EAP type for tunneled EAP session. (7) peap : Got tunneled request EAP-Message = 0x027c0015015a4f4f504c55535c6173646631323334 server { (7) peap : Setting User-Name to TEST\user1 Sending tunneled request EAP-Message = 0x027c0015015a4f4f504c55535c6173646631323334 FreeRADIUS-Proxied-To = 127.0.0.1 User-Name = "TEST\\user1" server inner-tunnel { (7) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/inner-tunnel (7) group authorize { (7) - entering group authorize {...} (7) [chap] = noop (7) [mschap] = noop (7) suffix : No '@' in User-Name = "TEST\user1", looking up realm NULL (7) suffix : No such realm "NULL" (7) [suffix] = noop (7) update control { (7) } # update control = noop (7) eap : EAP packet type response id 124 length 21 (7) eap : EAP-Identity reply, returning 'ok' so we can short-circuit the rest of authorize (7) [eap] = ok (7) Found Auth-Type = EAP (7) # Executing group from file /usr/local/etc/raddb/sites-enabled/inner-tunnel (7) group authenticate { (7) - entering group authenticate {...} (7) eap : EAP Identity (7) eap : processing type mschapv2 rlm_eap_mschapv2: Issuing Challenge (7) [eap] = handled } # server inner-tunnel (7) peap : Got tunneled reply code 11 EAP-Message = 0x017d002a1a017d002510ee147dab7777ab81d08e6d124679316a5a4f4f504c55535c6173646631323334 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x9d9cbe589de1a4d031f1fd4ff27cd0d2 (7) peap : Got tunneled reply RADIUS code 11 EAP-Message = 0x017d002a1a017d002510ee147dab7777ab81d08e6d124679316a5a4f4f504c55535c6173646631323334 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x9d9cbe589de1a4d031f1fd4ff27cd0d2 (7) peap : Got tunneled Access-Challenge (7) [eap] = handled Sending Access-Challenge of id 36 to 10.0.5.100 port 32783 EAP-Message = 0x017d004b19001703010040c66cade655df6d537e10ca7520aed7f9ca846d289258b8b60963e2133992e1294c215ed5cfb4cf73f7a60a8d098ed7cb4cd1cb1552d29063812d1762af58465e Message-Authenticator = 0x00000000000000000000000000000000 State = 0x233fc17e2442d8f3e83a34544ff58a3c (7) Finished request 7. Waking up in 0.1 seconds. rad_recv: Access-Request packet from host 10.0.5.100 port 32783, id=254, length=463 Acct-Multi-Session-Id = "00-A1-B1-4D-D4-78-A1-23-DF-79-F0-B9-4F-D7-38-03-00-0D-86-CF" Acct-Session-Id = "1d01db22-000000ea" NAS-Port = 218 NAS-Port-Type = Wireless-802.11 NAS-Identifier = "AccessPoint1" NAS-IP-Address = 10.0.1.50 Framed-MTU = 1496 User-Name = "TEST\\user1" Calling-Station-Id = "A1-23-DF-79-F0-B9" Called-Station-Id = "00-A1-B1-4D-D4-78" Service-Type = Framed-User EAP-Message = 0x027d006b19001703010060af1e4b00434bd2a75f4c3ccf0d8f189e6b2896f0adc6abd84d38260ec7cad6f927bfa09a70bde000d8ec160b763b57d71a9f103ff578c251f8bb9504f8c5a2fb5a9e64f7716940c33e5ce165519490a14575dcbc91eb2896ed1a4d9759d72148 State = 0x233fc17e2442d8f3e83a34544ff58a3c Attr-26 = 0x00002228000c737369643d7a706c5f320016696e636f6d696e672d766c616e2d69643d313238000f67726f75703d4dfc6e6368656e00127673632d756e697175652d69643d31300017706879747970653d49454545383032646f74313167 Attr-26.8744.250 = 0x00000003 Attr-26.8744.249 = 0xc0a81489 Message-Authenticator = 0x50a2fdf665bde54e7aeeab93fc7a9138 (8) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default (8) group authorize { (8) - entering group authorize {...} (8) [preprocess] = ok (8) [chap] = noop (8) [mschap] = noop (8) [digest] = noop (8) suffix : No '@' in User-Name = "TEST\user1", looking up realm NULL (8) suffix : No such realm "NULL" (8) [suffix] = noop (8) eap : EAP packet type response id 125 length 107 (8) eap : Continuing tunnel setup. (8) [eap] = ok (8) Found Auth-Type = EAP (8) # Executing group from file /usr/local/etc/raddb/sites-enabled/default (8) group authenticate { (8) - entering group authenticate {...} (8) eap : Request found, released from the list (8) eap : EAP/peap (8) eap : processing type peap (8) peap : processing EAP-TLS (8) peap : eaptls_verify returned 7 (8) peap : Done initial handshake (8) peap : eaptls_process returned 7 (8) peap : FR_TLS_OK (8) peap : Session established. Decoding tunneled attributes. (8) peap : Peap state phase2 (8) peap : EAP type mschapv2 (8) peap : Got tunneled request EAP-Message = 0x027d004b1a027d004631664019e4cf68c221dd4265b9f41a569e00000000000000008aacee551ce230cd14d51c517b26780d896edf4c1026c24f005a4f4f504c55535c6173646631323334 server { (8) peap : Setting User-Name to TEST\user1 Sending tunneled request EAP-Message = 0x027d004b1a027d004631664019e4cf68c221dd4265b9f41a569e00000000000000008aacee551ce230cd14d51c517b26780d896edf4c1026c24f005a4f4f504c55535c6173646631323334 FreeRADIUS-Proxied-To = 127.0.0.1 User-Name = "TEST\\user1" State = 0x9d9cbe589de1a4d031f1fd4ff27cd0d2 server inner-tunnel { (8) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/inner-tunnel (8) group authorize { (8) - entering group authorize {...} (8) [chap] = noop (8) [mschap] = noop (8) suffix : No '@' in User-Name = "TEST\user1", looking up realm NULL (8) suffix : No such realm "NULL" (8) [suffix] = noop (8) update control { (8) } # update control = noop (8) eap : EAP packet type response id 125 length 75 (8) eap : No EAP Start, assuming it's an on-going EAP conversation (8) [eap] = updated (8) files : users: Matched entry DEFAULT at line 205 (8) [files] = ok (8) [expiration] = noop (8) [logintime] = noop (8) [pap] = noop (8) Found Auth-Type = EAP (8) # Executing group from file /usr/local/etc/raddb/sites-enabled/inner-tunnel (8) group authenticate { (8) - entering group authenticate {...} (8) eap : Request found, released from the list (8) eap : EAP/mschapv2 (8) eap : processing type mschapv2 (8) mschapv2 : # Executing group from file /usr/local/etc/raddb/sites-enabled/inner-tunnel (8) mschapv2 : group MS-CHAP { (8) mschapv2 : - entering group MS-CHAP {...} (8) mschap : Creating challenge hash with username: asdf1234 (8) mschap : Told to do MS-CHAPv2 for asdf1234 with NT-Password (8) mschap : expand: %{Stripped-User-Name} -> (8) mschap : ... expanding second conditional (8) mschap : expand: %{User-Name} -> TEST\user1 (8) mschap : expand: %{%{User-Name}:-None} -> TEST\user1 (8) mschap : expand: --username=%{%{Stripped-User-Name}:-%{%{User-Name}:-None}} -> --username=TEST\user1 (8) mschap : Creating challenge hash with username: asdf1234 (8) mschap : expand: %{mschap:Challenge} -> 77bfad378970f10a (8) mschap : expand: --challenge=%{%{mschap:Challenge}:-00} -> --challenge=77bfad378970f10a (8) mschap : expand: %{mschap:NT-Response} -> 8aacee551ce230cd14d51c517b26780d896edf4c1026c24f (8) mschap : expand: --nt-response=%{%{mschap:NT-Response}:-00} -> --nt-response=8aacee551ce230cd14d51c517b26780d896edf4c1026c24f Exec-Program output: Must change password (0xc0000224) Exec-Program-Wait: plaintext: Must change password (0xc0000224) Exec-Program: returned: 1 (8) mschap : External script failed. (8) mschap : FAILED: MS-CHAP2-Response is incorrect (8) [mschap] = reject rlm_eap_mschapv2: No MS-CHAPv2-Success or MS-CHAP-Error was found. (8) eap : Handler failed in EAP/mschapv2 (8) eap : Failed in EAP select (8) [eap] = invalid (8) Failed to authenticate the user. } # server inner-tunnel (8) peap : Got tunneled reply code 3 MS-CHAP-Error = "}E=691 R=0 C=9247f7d726bf93f281dae5fe1ec145cf V=3 M=Re-enter (or reset) the password" EAP-Message = 0x047d0004 Message-Authenticator = 0x00000000000000000000000000000000 (8) peap : Got tunneled reply RADIUS code 3 MS-CHAP-Error = "}E=691 R=0 C=9247f7d726bf93f281dae5fe1ec145cf V=3 M=Re-enter (or reset) the password" EAP-Message = 0x047d0004 Message-Authenticator = 0x00000000000000000000000000000000 (8) peap : Tunneled authentication was rejected. (8) peap : FAILURE (8) [eap] = handled Sending Access-Challenge of id 254 to 10.0.5.100 port 32783 EAP-Message = 0x017e002b190017030100202710abb6cdf56f18475467e64ec4624bf711475bf2c28ef0061b7084e195e0c0 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x233fc17e2b41d8f3e83a34544ff58a3c (8) Finished request 8. Waking up in 0.1 seconds. rad_recv: Access-Request packet from host 10.0.5.100 port 32783, id=202, length=399 Acct-Multi-Session-Id = "00-A1-B1-4D-D4-78-A1-23-DF-79-F0-B9-4F-D7-38-03-00-0D-86-CF" Acct-Session-Id = "1d01db22-000000ea" NAS-Port = 218 NAS-Port-Type = Wireless-802.11 NAS-Identifier = "AccessPoint1" NAS-IP-Address = 10.0.1.50 Framed-MTU = 1496 User-Name = "TEST\\user1" Calling-Station-Id = "A1-23-DF-79-F0-B9" Called-Station-Id = "00-A1-B1-4D-D4-78" Service-Type = Framed-User EAP-Message = 0x027e002b19001703010020ce53a51bb41f504fab4bd8b2443460e86422697ed22c2e9680d9fb4a673fa6b1 State = 0x233fc17e2b41d8f3e83a34544ff58a3c Attr-26 = 0x00002228000c737369643d7a706c5f320016696e636f6d696e672d766c616e2d69643d313238000f67726f75703d4dfc6e6368656e00127673632d756e697175652d69643d31300017706879747970653d49454545383032646f74313167 Attr-26.8744.250 = 0x00000003 Attr-26.8744.249 = 0xc0a81489 Message-Authenticator = 0xd5a792fd0f47b601d1a818f1c3fe959f (9) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default (9) group authorize { (9) - entering group authorize {...} (9) [preprocess] = ok (9) [chap] = noop (9) [mschap] = noop (9) [digest] = noop (9) suffix : No '@' in User-Name = "TEST\user1", looking up realm NULL (9) suffix : No such realm "NULL" (9) [suffix] = noop (9) eap : EAP packet type response id 126 length 43 (9) eap : Continuing tunnel setup. (9) [eap] = ok (9) Found Auth-Type = EAP (9) # Executing group from file /usr/local/etc/raddb/sites-enabled/default (9) group authenticate { (9) - entering group authenticate {...} (9) eap : Request found, released from the list (9) eap : EAP/peap (9) eap : processing type peap (9) peap : processing EAP-TLS (9) peap : eaptls_verify returned 7 (9) peap : Done initial handshake (9) peap : eaptls_process returned 7 (9) peap : FR_TLS_OK (9) peap : Session established. Decoding tunneled attributes. (9) peap : Peap state send tlv failure (9) peap : Received EAP-TLV response. (9) peap : The users session was previously rejected: returning reject (again.) (9) peap : *** This means you need to read the PREVIOUS messages in the debug output (9) peap : *** to find out the reason why the user was rejected. (9) peap : *** Look for "reject" or "fail". Those earlier messages will tell you. (9) peap : *** what went wrong, and how to fix the problem. SSL: Removing session f3ed404d9531a40bbcad0cadbad4133c4ad48296899ea27022fc32535d459cf0 from the cache (9) eap : Handler failed in EAP/peap (9) eap : Failed in EAP select (9) [eap] = invalid (9) Failed to authenticate the user. (9) Using Post-Auth-Type Reject (9) # Executing group from file /usr/local/etc/raddb/sites-enabled/default (9) group REJECT { (9) - entering group REJECT {...} (9) attr_filter.access_reject : expand: %{User-Name} -> TEST\user1 (9) attr_filter.access_reject : Matched entry DEFAULT at line 11 (9) [attr_filter.access_reject] = updated (9) eap : Reply already contained an EAP-Message, not inserting EAP-Failure (9) [eap] = noop (9) policy remove_reply_message_if_eap { (9) - entering policy remove_reply_message_if_eap {...} (9) ? if (reply:EAP-Message && reply:Reply-Message) (9) ? Evaluating (reply:EAP-Message ) -> TRUE (9) ? Evaluating (reply:Reply-Message) -> FALSE (9) ? if (reply:EAP-Message && reply:Reply-Message) -> FALSE (9) else else { (9) - entering else else {...} (9) [noop] = noop (9) - else else returns noop (9) - policy remove_reply_message_if_eap returns noop (9) Finished request 9. Waking up in 0.6 seconds. (9) Sending delayed reject Sending Access-Reject of id 202 to 10.0.5.100 port 32783 EAP-Message = 0x047e0004 Message-Authenticator = 0x00000000000000000000000000000000 Waking up in 3.7 seconds. (0) Cleaning up request packet ID 106 with timestamp +7 (1) Cleaning up request packet ID 226 with timestamp +7 (2) Cleaning up request packet ID 207 with timestamp +7 (3) Cleaning up request packet ID 156 with timestamp +7 (4) Cleaning up request packet ID 11 with timestamp +7 (5) Cleaning up request packet ID 248 with timestamp +7 (6) Cleaning up request packet ID 236 with timestamp +7 (7) Cleaning up request packet ID 36 with timestamp +7 (8) Cleaning up request packet ID 254 with timestamp +7 Waking up in 1.0 seconds. (9) Cleaning up request packet ID 202 with timestamp +7 Ready to process requests. -- NEU: FreePhone 3-fach-Flat mit kostenlosem Smartphone! Jetzt informieren: http://mobile.1und1.de/?ac=OM.PW.PW003K20328T7073a
On 06/12/2012 06:47 PM, CD DD wrote:
Exec-Program output: Must change password (0xc0000224) Exec-Program-Wait: plaintext: Must change password (0xc0000224)
Ok. ntlm_auth is returning something different to what I saw in testing. Have you set the "must change password at next login" bit, as opposed to "expired" bit? Try this: 1. Edit src/modules/rlm_mschap/rlm_mschap.c about line 1100, where it says: if (strstr(buffer, "Password expired")) { ...to read: if (strstr(buffer, "Password expired") || strstr(buffer, "Must change password")) { 2. Re-compile and re-install 3. Test again There's no great way to parse the output of ntlm_auth. I guess we could make the string a regexp comparison against the output, and at least make it an item in the config file (with a sensible default) so that if more such cases come up, or Samba change their output, it can be fixed without a recompile.
CD DD wrote:
The MSCHAP password change code looks for the string "Password expired" in the output of the ntlm_auth command. If your ntlm_auth is printing something different, it'll just assume it's a regular failure.
Sure, here are the Debug output:
Which doesn't contain the string "Password expired". That's why it's failing.
Exec-Program output: Must change password (0xc0000224) Exec-Program-Wait: plaintext: Must change password (0xc0000224) Exec-Program: returned: 1
Phil already explained this. The debug log (while large) is pretty clear on this. I'll take a look to see if it can be fixed before the next release. Alan DeKok.
participants (3)
-
Alan DeKok -
CD DD -
Phil Mayers