- Freeradius-Users - lists.freeradius.org

[mschap] FAILED: MS-CHAP2-Response is incorrect
by sekchel lee 28 Sep '11

28 Sep '11

mysql> select * from radcheck; +----+------------+---------------+----+------------------------------------+ | id | username | attribute | op | value | +----+------------+---------------+----+------------------------------------+ | 1 | testuser | User-Password | := | $1$vQGXHdnO$7DjKbeUeAadrsfGg8thE2. | FreeRADIUS Version 2.1.7, for host i686-redhat-linux-gnu, built on Mar 31 2010 at 00:25:31 Copyright (C) 1999-2009 The FreeRADIUS server project and contributors. There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. You may redistribute copies of FreeRADIUS under the terms of the GNU General Public License v2. Starting - reading configuration files ... including configuration file /etc/raddb/radiusd.conf including configuration file /etc/raddb/proxy.conf including configuration file /etc/raddb/clients.conf including files in directory /etc/raddb/modules/ including configuration file /etc/raddb/modules/otp including configuration file /etc/raddb/modules/detail.example.com including configuration file /etc/raddb/modules/files including configuration file /etc/raddb/modules/sql_log including configuration file /etc/raddb/modules/attr_filter including configuration file /etc/raddb/modules/wimax including configuration file /etc/raddb/modules/preprocess including configuration file /etc/raddb/modules/mac2vlan including configuration file /etc/raddb/modules/detail including configuration file /etc/raddb/modules/expiration including configuration file /etc/raddb/modules/inner-eap including configuration file /etc/raddb/modules/policy including configuration file /etc/raddb/modules/realm including configuration file /etc/raddb/modules/attr_rewrite including configuration file /etc/raddb/modules/linelog including configuration file /etc/raddb/modules/cui including configuration file /etc/raddb/modules/smbpasswd including configuration file /etc/raddb/modules/smsotp including configuration file /etc/raddb/modules/always including configuration file /etc/raddb/modules/sradutmp including configuration file /etc/raddb/modules/digest including configuration file /etc/raddb/modules/expr including configuration file /etc/raddb/modules/pam including configuration file /etc/raddb/modules/checkval including configuration file /etc/raddb/modules/exec including configuration file /etc/raddb/modules/mac2ip including configuration file /etc/raddb/modules/perl including configuration file /etc/raddb/modules/radutmp including configuration file /etc/raddb/modules/mschap including configuration file /etc/raddb/modules/unix including configuration file /etc/raddb/modules/logintime including configuration file /etc/raddb/modules/ippool including configuration file /etc/raddb/modules/etc_group including configuration file /etc/raddb/modules/pap including configuration file /etc/raddb/modules/echo including configuration file /etc/raddb/modules/passwd including configuration file /etc/raddb/modules/chap including configuration file /etc/raddb/modules/acct_unique including configuration file /etc/raddb/modules/sqlcounter_expire_on_login including configuration file /etc/raddb/modules/detail.log including configuration file /etc/raddb/modules/counter including configuration file /etc/raddb/eap.conf including configuration file /etc/raddb/sql.conf including configuration file /etc/raddb/sql/mysql/dialup.conf including configuration file /etc/raddb/sql/mysql/counter.conf including configuration file /etc/raddb/sqlippool.conf including configuration file /etc/raddb/sql/mysql/ippool.conf including configuration file /etc/raddb/policy.conf including files in directory /etc/raddb/sites-enabled/ including configuration file /etc/raddb/sites-enabled/inner-tunnel including configuration file /etc/raddb/sites-enabled/control-socket including configuration file /etc/raddb/sites-enabled/default group = radiusd user = radiusd including dictionary file /etc/raddb/dictionary main { prefix = "/usr" localstatedir = "/var" logdir = "/var/log/radius" libdir = "/usr/lib/freeradius" radacctdir = "/var/log/radius/radacct" hostname_lookups = no max_request_time = 30 cleanup_delay = 5 max_requests = 1024 allow_core_dumps = no pidfile = "/var/run/radiusd/radiusd.pid" checkrad = "/usr/sbin/checkrad" debug_level = 0 proxy_requests = no log { stripped_names = no auth = no auth_badpass = no auth_goodpass = no } security { max_attributes = 200 reject_delay = 1 status_server = yes } } radiusd: #### Loading Realms and Home Servers #### proxy server { retry_delay = 5 retry_count = 3 default_fallback = no dead_time = 120 wake_all_if_all_dead = no } home_server localhost { ipaddr = 127.0.0.1 port = 1812 type = "auth" secret = "testing123" response_window = 20 max_outstanding = 65536 require_message_authenticator = no zombie_period = 40 status_check = "status-server" ping_interval = 30 check_interval = 30 num_answers_to_alive = 3 num_pings_to_alive = 3 revive_interval = 120 status_check_timeout = 4 irt = 2 mrt = 16 mrc = 5 mrd = 30 } home_server_pool my_auth_failover { type = fail-over home_server = localhost } realm example.com { auth_pool = my_auth_failover } realm LOCAL { } radiusd: #### Loading Clients #### client xxx.xx.xxx.124 { ipaddr = xx0.xx.xxx.124 require_message_authenticator = no secret = "test1234" nastype = "other" } radiusd: #### Instantiating modules #### instantiate { Module: Linked to module rlm_exec Module: Instantiating exec exec { wait = no input_pairs = "request" shell_escape = yes } Module: Linked to module rlm_expr Module: Instantiating expr Module: Linked to module rlm_expiration Module: Instantiating expiration expiration { reply-message = "Password Has Expired " } Module: Linked to module rlm_logintime Module: Instantiating logintime logintime { reply-message = "You are calling outside your allowed timespan " minimum-timeout = 60 } } radiusd: #### Loading Virtual Servers #### server inner-tunnel { modules { Module: Checking authenticate {...} for more modules to load Module: Linked to module rlm_pap Module: Instantiating pap pap { encryption_scheme = "auto" auto_header = no } Module: Linked to module rlm_chap Module: Instantiating chap Module: Linked to module rlm_mschap Module: Instantiating mschap mschap { use_mppe = no require_encryption = no require_strong = no with_ntdomain_hack = no } Module: Linked to module rlm_unix Module: Instantiating unix unix { radwtmp = "/var/log/radius/radwtmp" } Module: Linked to module rlm_eap Module: Instantiating eap eap { default_eap_type = "md5" timer_expire = 60 ignore_unknown_eap_types = no cisco_accounting_username_bug = no max_sessions = 2048 } Module: Linked to sub-module rlm_eap_md5 Module: Instantiating eap-md5 Module: Linked to sub-module rlm_eap_leap Module: Instantiating eap-leap Module: Linked to sub-module rlm_eap_gtc Module: Instantiating eap-gtc gtc { challenge = "Password: " auth_type = "PAP" } Module: Linked to sub-module rlm_eap_tls Module: Instantiating eap-tls tls { rsa_key_exchange = no dh_key_exchange = yes rsa_key_length = 512 dh_key_length = 512 verify_depth = 0 pem_file_type = yes private_key_file = "/etc/raddb/certs/server.pem" certificate_file = "/etc/raddb/certs/server.pem" CA_file = "/etc/raddb/certs/ca.pem" private_key_password = "whatever" dh_file = "/etc/raddb/certs/dh" random_file = "/etc/raddb/certs/random" fragment_size = 1024 include_length = yes check_crl = no cipher_list = "DEFAULT" make_cert_command = "/etc/raddb/certs/bootstrap" cache { enable = no lifetime = 24 max_entries = 255 } } Module: Linked to sub-module rlm_eap_ttls Module: Instantiating eap-ttls ttls { default_eap_type = "md5" copy_request_to_tunnel = no use_tunneled_reply = no virtual_server = "inner-tunnel" include_length = yes } Module: Linked to sub-module rlm_eap_peap Module: Instantiating eap-peap peap { default_eap_type = "mschapv2" copy_request_to_tunnel = no use_tunneled_reply = no proxy_tunneled_request_as_eap = yes virtual_server = "inner-tunnel" } Module: Linked to sub-module rlm_eap_mschapv2 Module: Instantiating eap-mschapv2 mschapv2 { with_ntdomain_hack = no } Module: Checking authorize {...} for more modules to load Module: Linked to module rlm_realm Module: Instantiating suffix realm suffix { format = "suffix" delimiter = "@" ignore_default = no ignore_null = no } Module: Linked to module rlm_files Module: Instantiating files files { usersfile = "/etc/raddb/users" acctusersfile = "/etc/raddb/acct_users" preproxy_usersfile = "/etc/raddb/preproxy_users" compat = "no" } Module: Checking session {...} for more modules to load Module: Linked to module rlm_radutmp Module: Instantiating radutmp radutmp { filename = "/var/log/radius/radutmp" username = "%{User-Name}" case_sensitive = yes check_with_nas = yes perm = 384 callerid = yes } Module: Checking post-proxy {...} for more modules to load Module: Checking post-auth {...} for more modules to load Module: Linked to module rlm_attr_filter Module: Instantiating attr_filter.access_reject attr_filter attr_filter.access_reject { attrsfile = "/etc/raddb/attrs.access_reject" key = "%{User-Name}" } } # modules } # server server { modules { Module: Checking authenticate {...} for more modules to load Module: Checking authorize {...} for more modules to load Module: Linked to module rlm_preprocess Module: Instantiating preprocess preprocess { huntgroups = "/etc/raddb/huntgroups" hints = "/etc/raddb/hints" with_ascend_hack = no ascend_channels_per_line = 23 with_ntdomain_hack = no with_specialix_jetstream_hack = no with_cisco_vsa_hack = no with_alvarion_vsa_hack = no } Module: Checking preacct {...} for more modules to load Module: Linked to module rlm_acct_unique Module: Instantiating acct_unique acct_unique { key = "User-Name, Acct-Session-Id, NAS-IP-Address, Client-IP-Address, NAS-Port" } Module: Checking accounting {...} for more modules to load Module: Linked to module rlm_detail Module: Instantiating detail detail { detailfile = "/var/log/radius/radacct/%{Client-IP-Address}/detail-%Y%m%d" header = "%t" detailperm = 384 dirperm = 493 locking = no log_packet_header = no } Module: Instantiating attr_filter.accounting_response attr_filter attr_filter.accounting_response { attrsfile = "/etc/raddb/attrs.accounting_response" key = "%{User-Name}" } Module: Checking session {...} for more modules to load Module: Checking post-proxy {...} for more modules to load Module: Checking post-auth {...} for more modules to load } # modules } # server radiusd: #### Opening IP addresses and Ports #### listen { type = "auth" ipaddr = * port = 0 } listen { type = "acct" ipaddr = * port = 0 } listen { type = "control" listen { socket = "/var/run/radiusd/radiusd.sock" } } Listening on authentication address * port 1812 Listening on accounting address * port 1813 Listening on command file /var/run/radiusd/radiusd.sock Ready to process requests. rad_recv: Access-Request packet from host xxx.xx.xxx.124 port 45736, id=85, length=153 Service-Type = Framed-User Framed-Protocol = PPP User-Name = "testuser" MS-CHAP-Challenge = 0x3ee4b2159d1bb98a2346bc0486f40c76 MS-CHAP2-Response = 0x810075b62261a0af713e9ea1efa6847ab7b8000000000000000020fd3c4aa07aa4adcc5fc0b9c6b8a8245ec3a2d2399a5df8 Calling-Station-Id = "xx.xx.229.203" NAS-IP-Address = 127.0.0.1 NAS-Port = 0 +- entering group authorize {...} ++[preprocess] returns ok ++[chap] returns noop [mschap] Found MS-CHAP attributes. Setting 'Auth-Type = mschap' ++[mschap] returns ok [suffix] No '@' in User-Name = "testuser", looking up realm NULL [suffix] No such realm "NULL" ++[suffix] returns noop [eap] No EAP-Message, not doing EAP ++[eap] returns noop ++[unix] returns notfound [files] users: Matched entry DEFAULT at line 172 ++[files] returns ok ++[expiration] returns noop ++[logintime] returns noop [pap] WARNING! No "known good" password found for the user. Authentication may fail because of this. ++[pap] returns noop Found Auth-Type = MSCHAP +- entering group MS-CHAP {...} [mschap] No Cleartext-Password configured. Cannot create LM-Password. [mschap] No Cleartext-Password configured. Cannot create NT-Password. [mschap] Told to do MS-CHAPv2 for testuser with NT-Password [mschap] FAILED: No NT/LM-Password. Cannot perform authentication. [mschap] FAILED: MS-CHAP2-Response is incorrect ++[mschap] returns reject Failed to authenticate the user. Using Post-Auth-Type Reject +- entering group REJECT {...} [attr_filter.access_reject] expand: %{User-Name} -> testuser attr_filter: Matched entry DEFAULT at line 11 ++[attr_filter.access_reject] returns updated Delaying reject of request 0 for 1 seconds Going to the next request Waking up in 0.9 seconds. Sending delayed reject for request 0 Sending Access-Reject of id 85 to xxx.xx.xxx.124 port 45736 Waking up in 4.9 seconds. Cleaning up request 0 ID 85 with timestamp +7 Ready to process requests.

2 1

couldn't link driver rlm_sql_mysql
by gary 28 Sep '11

28 Sep '11

Hi All I am setting up freeradius 2.1.11+mysql 5.5.16 on Fedora 13. Executing command "radiusd -X" it says could not link driver rlm_sql_mysql(read as below). It not worked even I install "freeradius-mysql" library but I can find the driver "rlm_sql_mysql.so" in "/usr/lib/freeradius" folder. Anyone can help me? ################################################################### #radiusd -X Could not link driver rlm_sql_mysql: rlm_sql_mysql.so: cannot open shared object file: No such file or directory Make sure it (and all its dependent libraries!) are in the search path of your system's ld. /usr/local/etc/raddb/sql.conf[22]: Instantiation failed for module "sql" /usr/local/etc/raddb/sites-enabled/default[166]: Failed to load module "sql". /usr/local/etc/raddb/sites-enabled/default[69]: Errors parsing authorize section. ################################################################## Best Regards Gary

3 3

Re: MySQL and FreeRADIUS environment.
by Alan Buxey 27 Sep '11

27 Sep '11

Master/slave, or replication and remote accounting, if you want one true source let radius deal with the sql rather than trying anything with sql. Final advice would be to use postgresql rather than mysql, our performance increase was a magnitude better when we ditched mysql alan

2 1

Help desk support of authn/authz failures? Logging detailed messages to SQL?
by Jason Antman 27 Sep '11

27 Sep '11

We've rolled out FreeRADIUS as the authentication and authorization server for our University-wide WLAN with 30,000+ users. Our help desk (general IT, not wireless-specific) support staff is made up of student workers, with full-time second-level support and us sysadmins/wireless engineers for third-level support. As we've rolled out WPA2 and the supplicants give no useful information about authentication failures to end-users, our help desk is being inundated with "help, I can't login" calls. We do auth logging to MySQL. Help desk staff are not given access to our authentication servers, so our current solution is to use lots of unlang config kludge in authorize{} to defer any notfound or reject module responses (configurable failover), then use if statements to check the actual return of the module. If it's a "bad" user (notfound, reject, etc.) we set a locally-defined string attribute (control:Reject-Reason) and then reject the user, and Post-Auth Type Reject logs to SQL including that string reason. Which is then accessible in a read-only web tool for the help desk. 1) How do other people - specifically organizations with a help desk large enough that they're distinctly separate from anyone with enough privs to tail a log file - handle user support of authentication failures? 2) This is proving problematic with users who have EAP misconfigurations, empty LDAP passwords, etc. that only manifest as a module failure and only show up in the log file. I've been considering patching the relevant modules to add/update an attribute on failure, since currently AFAIK this information is only available in the log file, and not anywhere that I can include in the SQL post-auth log. Has anyone else done anything similar? Or is more detailed module failure information accessible through something that I haven't been able to find in the docs? Thanks for any advice/insights, Jason -- Jason Antman System Administrator Rutgers University OIT Central Systems & Services / NetOps Office: 732-445-6363 Cell: 732-983-7256 jantman(a)oit.rutgers.edu

3 4

Problem "expand: %{Acct-Input-Gigawords} ->" always get nothing!
by snan4love 27 Sep '11

27 Sep '11

Hello Everybody: Thanks for opening this topic. Right now,I have set up the FreeRadius+Mysql+Wifi system, I could get into the internet via this system on my laptop. But my problem is : No matter how long i stay in the connection, the AcctInputOctets and AcctOutPutOctets are always 0; the debug information from radiusd -X mode regarding this issue is : [sql] expand: %{User-Name} -> snan4love [sql] sql_set_user escaped user --> 'snan4love' [sql] expand: %{Acct-Input-Gigawords} -> [sql] ... expanding second conditional [sql] expand: %{Acct-Input-Octets} -> [sql] ... expanding second conditional [sql] expand: %{Acct-Output-Gigawords} -> [sql] ... expanding second conditional [sql] expand: %{Acct-Output-Octets} -> [sql] ... expanding second conditional [sql] expand: %{Acct-Delay-Time} -> [sql] ... expanding second conditional [sql] expand: UPDATE radacct SET acctstoptime = '%S', acctsessiontime = '%{Acct-Session-Time}', acctinputoctets = '%{%{Acct-Input-Gigawords}:-0}' << 32 | '%{%{Acct-Input-Octets}:-0}', acctoutputoctets = '%{%{Acct-Output-Gigawords}:-0}' << 32 | '%{%{Acct-Output-Octets}:-0}', acctterminatecause = '%{Acct-Terminate-Cause}', acctstopdelay = '%{%{Acct-Delay-Time}:-0}', connectinfo_stop = '%{Connect-Info}' WHERE acctsessionid = '%{Acct-Session-Id}' AND username = '%{SQL-User-Name}' AND nasipaddress = '%{NAS-IP-Address}' -> UPDATE radacct SET acctstoptime = '2011-09-27 15:45:35', acctsessiontime = '1317', acctinputoctets = '0' << 32 | '0', acctoutputoctets = '0' << 32 | Every expand:%{Acct-Input-...} will get nothing. I know,there must be misconfiguration I made, but I dont know where to fix it. Please help me, Thank you very much. -- View this message in context: http://freeradius.1045715.n5.nabble.com/Problem-expand-Acct-Input-Gigawords… Sent from the FreeRadius - User mailing list archive at Nabble.com.

4 11

EAP authentication accept, user not found
by andreapepa 27 Sep '11

27 Sep '11

Hi all, I'm wondering if my freeradius is acting correctly against the request below: This Mikrotik CPE is authenticathing by an EAP certificate and ad a username with password is requested. The problem is that the CPE is authenticated with every username that doesn't exist in radcheck. why FR authenticate even with nonexistent username? rad_recv: Access-Request packet from host 10.25.66.8 port 56485, id=162, length=175 Service-Type = Framed-User Framed-MTU = 1400 User-Name = "test155" State = 0x06c5601b03c36da7f69234e83e184b70 NAS-Port-Id = "wlan2" Calling-Station-Id = "00-0C-42-B3-D1-F5" Called-Station-Id = "00-80-48-60-66-D9:WiNET-TR5G506106" EAP-Message = 0x020600060d00 Message-Authenticator = 0xd549039a41edfd3e25ff22bdb1f16d60 NAS-Identifier = "ced-wl3" NAS-IP-Address = 10.25.66.8 # Executing section authorize from file /etc/freeradius/sites-enabled/default +- entering group authorize {...} ++[preprocess] returns ok [auth_log] expand: /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/freeradius/radacct/10.25.66.8/auth-detail-20110926 [auth_log] /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/10.25.66.8/auth-detail-20110926 [auth_log] expand: %t -> Mon Sep 26 16:35:21 2011 ++[auth_log] returns ok ++[chap] returns noop ++[mschap] returns noop ++[digest] returns noop [suffix] No '@' in User-Name = "test155", looking up realm NULL [suffix] No such realm "NULL" ++[suffix] returns noop [eap] EAP packet type response id 6 length 6 [eap] No EAP Start, assuming it's an on-going EAP conversation ++[eap] returns updated ++[files] returns noop [sql] expand: %{User-Name} -> test155 [sql] sql_set_user escaped user --> 'test155' rlm_sql (sql): Reserving sql socket id: 19 [sql] expand: SELECT id, UserName, Attribute, Value, Op FROM radcheck WHERE Username = '%{SQL-User-Name}' ORDER BY id -> SELECT id, UserName, Attribute, Value, Op FROM radcheck WHERE Username = 'test155' ORDER BY id rlm_sql_postgresql: query: SELECT id, UserName, Attribute, Value, Op FROM radcheck WHERE Username = 'test155' ORDER BY id rlm_sql_postgresql: Status: PGRES_TUPLES_OK rlm_sql_postgresql: query affected rows = 0 , fields = 5 [sql] expand: SELECT GroupName FROM radusergroup WHERE UserName='%{SQL-User-Name}' ORDER BY priority -> SELECT GroupName FROM radusergroup WHERE UserName='test155' ORDER BY priority rlm_sql_postgresql: query: SELECT GroupName FROM radusergroup WHERE UserName='test155' ORDER BY priority rlm_sql_postgresql: Status: PGRES_TUPLES_OK rlm_sql_postgresql: query affected rows = 0 , fields = 1 rlm_sql (sql): Released sql socket id: 19 [sql] User test155 not found ++[sql] returns notfound ++[expiration] returns noop ++[logintime] returns noop ++[pap] returns noop Found Auth-Type = EAP # Executing group from file /etc/freeradius/sites-enabled/default +- entering group authenticate {...} [eap] Request found, released from the list [eap] EAP/tls [eap] processing type tls [tls] Authenticate [tls] processing EAP-TLS [tls] Received TLS ACK [tls] ACK handshake is finished [tls] eaptls_verify returned 3 [tls] eaptls_process returned 3 [tls] Adding user data to cached session [eap] Freeing handler ++[eap] returns ok Login OK: [test155] (from client ced-wl3 port 0 cli 00-0C-42-B3-D1-F5) # Executing section post-auth from file /etc/freeradius/sites-enabled/default +- entering group post-auth {...} ++[exec] returns noop Sending Access-Accept of id 162 to 10.25.66.8 port 56485 MS-MPPE-Recv-Key = 0xd020f7a2efbb05c6fb255fe6665a12f09f354bdaa6d01b3d5d2c0786b07ca440 MS-MPPE-Send-Key = 0xa77aaf208423b318ff7f482401d4468af3f9248cbdb611857a5f356bea7725ca EAP-Message = 0x03060004 Message-Authenticator = 0x00000000000000000000000000000000 User-Name = "test155" Finished request 69. -- View this message in context: http://freeradius.1045715.n5.nabble.com/EAP-authentication-accept-user-not-… Sent from the FreeRadius - User mailing list archive at Nabble.com.

3 6

Radius + Samba + Mysql?
by Andreas Rudat 27 Sep '11

27 Sep '11

Hi, is that combination possible? Radius and Samba should use the same sql database for accounting. Are there any problems or hints? Thanks Andreas

3 8

Post-auth and Rejected logins
by Johan Meiring 26 Sep '11

26 Sep '11

Hi, Hope the following makes sense. I have a perl module that runs in post-auth. It checks various things that confirms whether the user may have access and, if not, would turn an Accept into a Reject. I want this perl module to run whether the authentication previously failed or not. I'm using the documented method of the following: post-auth { my_perl Post-Auth-Type REJECT { my_perl } } The problem comes in here. If authentication failed, the module runs once only (in the Post-Auth-Type REJECT stanza) If authentication was OK, and my perl module also OK's the request, it runs once only (in the "non" Post-Auth_type REJECT stanza). But.... If the auhtentication as OK, and my perl module then decides to reject the Authentication (by returning RLM_MODULE_REJECT), the perl module runs twice. I've tried swopping around the post-auth section as follows: post-auth { Post-Auth-Type REJECT { my_perl } my_perl } The "REJECT" stanza is still executed if the non-"REJECT" stanza turns the accept into a reject. The only solution I can come up with is to set a Tmp-String, and using unlang try to force the perl to not run again. Does anyone know of a more elegant way? Thanks! -- Johan Meiring Cape PC Services CC Tel: (021) 883-8271 Fax: (021) 886-7782 -------------------- Before acting on this email or opening any attachments you should read Cape PC Service's email disclaimer at: http://www.pcservices.co.za/disclaimer.html

2 2

[mschap] ERROR: User-Name (RC24558\jojo) is not the same as MS-CHAP Name (jojo) from EAP-MSCHAPv2
by scoth 26 Sep '11

26 Sep '11

I'm hoping someone can help me here. I've been working for a few days now trying to figure out what is wrong. I'm trying to use FreeRadius to authenticate wireless users. Apple devices and Windows 7 logs in fine. It seems these devices send just the username/password. XP is giving me the problems. I have a XP SP3 laptop setup for automatic join of the wireless network testing. The wireless connection is using WPA - TKIP, PEAP, MSCHAPv2, Enable Fast Reconnect, Automatically use my Windows logon name/password, connect to this network automatically. I'm testing this way because we eventually will let teachers and students bring their own laptops and connect to the wireless network. Going one-to-one for each student having a laptop is still not affordable. I will post my logs. It seems I can get the user jojo (test user) to connect and then authorize to ldap. Then authenticate to ldap but once the eap tunnel is build i get the error. [mschap] ERROR: User-Name (RC24558\jojo) is not the same as MS-CHAP Name (jojo) from EAP-MSCHAPv2 Thanks for anyone giving me your time on this. Here is my log: [root@rh6dev sbin]# ./radiusd -XXX Mon Sep 26 09:18:24 2011 : Info: FreeRADIUS Version 2.1.11, for host x86_64-unknown-linux-gnu, built on Jul 19 2011 at 10:04:23 Mon Sep 26 09:18:24 2011 : Info: Copyright (C) 1999-2009 The FreeRADIUS server project and contributors. Mon Sep 26 09:18:24 2011 : Info: There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A Mon Sep 26 09:18:24 2011 : Info: PARTICULAR PURPOSE. Mon Sep 26 09:18:24 2011 : Info: You may redistribute copies of FreeRADIUS under the terms of the Mon Sep 26 09:18:24 2011 : Info: GNU General Public License v2. Mon Sep 26 09:18:24 2011 : Info: Starting - reading configuration files ... Mon Sep 26 09:18:24 2011 : Debug: including configuration file /usr/local/etc/raddb/radiusd.conf Mon Sep 26 09:18:24 2011 : Debug: including configuration file /usr/local/etc/raddb/proxy.conf Mon Sep 26 09:18:24 2011 : Debug: including configuration file /usr/local/etc/raddb/clients.conf Mon Sep 26 09:18:24 2011 : Debug: including files in directory /usr/local/etc/raddb/modules/ Mon Sep 26 09:18:24 2011 : Debug: including configuration file /usr/local/etc/raddb/modules/pap Mon Sep 26 09:18:24 2011 : Debug: including configuration file /usr/local/etc/raddb/modules/mschap Mon Sep 26 09:18:24 2011 : Debug: including configuration file /usr/local/etc/raddb/modules/sqlcounter_expire_on_login Mon Sep 26 09:18:24 2011 : Debug: including configuration file /usr/local/etc/raddb/modules/ntlm_auth Mon Sep 26 09:18:24 2011 : Debug: including configuration file /usr/local/etc/raddb/modules/expiration Mon Sep 26 09:18:24 2011 : Debug: including configuration file /usr/local/etc/raddb/modules/always Mon Sep 26 09:18:24 2011 : Debug: including configuration file /usr/local/etc/raddb/modules/otp Mon Sep 26 09:18:24 2011 : Debug: including configuration file /usr/local/etc/raddb/modules/acct_unique Mon Sep 26 09:18:24 2011 : Debug: including configuration file /usr/local/etc/raddb/modules/preprocess Mon Sep 26 09:18:24 2011 : Debug: including configuration file /usr/local/etc/raddb/modules/linelog Mon Sep 26 09:18:24 2011 : Debug: including configuration file /usr/local/etc/raddb/modules/soh Mon Sep 26 09:18:24 2011 : Debug: including configuration file /usr/local/etc/raddb/modules/radutmp Mon Sep 26 09:18:24 2011 : Debug: including configuration file /usr/local/etc/raddb/modules/dynamic_clients Mon Sep 26 09:18:24 2011 : Debug: including configuration file /usr/local/etc/raddb/modules/policy Mon Sep 26 09:18:24 2011 : Debug: including configuration file /usr/local/etc/raddb/modules/echo Mon Sep 26 09:18:24 2011 : Debug: including configuration file /usr/local/etc/raddb/modules/logintime Mon Sep 26 09:18:24 2011 : Debug: including configuration file /usr/local/etc/raddb/modules/attr_filter Mon Sep 26 09:18:24 2011 : Debug: including configuration file /usr/local/etc/raddb/modules/strip_off_domain Mon Sep 26 09:18:24 2011 : Debug: including configuration file /usr/local/etc/raddb/modules/unix Mon Sep 26 09:18:24 2011 : Debug: including configuration file /usr/local/etc/raddb/modules/ldap.orig Mon Sep 26 09:18:24 2011 : Debug: including configuration file /usr/local/etc/raddb/modules/sradutmp Mon Sep 26 09:18:24 2011 : Debug: including configuration file /usr/local/etc/raddb/modules/expr Mon Sep 26 09:18:24 2011 : Debug: including configuration file /usr/local/etc/raddb/modules/perl Mon Sep 26 09:18:24 2011 : Debug: including configuration file /usr/local/etc/raddb/modules/inner-eap Mon Sep 26 09:18:24 2011 : Debug: including configuration file /usr/local/etc/raddb/modules/krb5 Mon Sep 26 09:18:24 2011 : Debug: including configuration file /usr/local/etc/raddb/modules/ippool Mon Sep 26 09:18:24 2011 : Debug: including configuration file /usr/local/etc/raddb/modules/exec Mon Sep 26 09:18:24 2011 : Debug: including configuration file /usr/local/etc/raddb/modules/attr_rewrite Mon Sep 26 09:18:24 2011 : Debug: including configuration file /usr/local/etc/raddb/modules/replicate Mon Sep 26 09:18:24 2011 : Debug: including configuration file /usr/local/etc/raddb/modules/wimax Mon Sep 26 09:18:24 2011 : Debug: including configuration file /usr/local/etc/raddb/modules/detail.example.com Mon Sep 26 09:18:24 2011 : Debug: including configuration file /usr/local/etc/raddb/modules/digest Mon Sep 26 09:18:24 2011 : Debug: including configuration file /usr/local/etc/raddb/modules/mac2vlan Mon Sep 26 09:18:24 2011 : Debug: including configuration file /usr/local/etc/raddb/modules/sql_log Mon Sep 26 09:18:24 2011 : Debug: including configuration file /usr/local/etc/raddb/modules/mac2ip Mon Sep 26 09:18:24 2011 : Debug: including configuration file /usr/local/etc/raddb/modules/detail Mon Sep 26 09:18:24 2011 : Debug: including configuration file /usr/local/etc/raddb/modules/ldap Mon Sep 26 09:18:24 2011 : Debug: including configuration file /usr/local/etc/raddb/modules/rediswho Mon Sep 26 09:18:24 2011 : Debug: including configuration file /usr/local/etc/raddb/modules/counter Mon Sep 26 09:18:24 2011 : Debug: including configuration file /usr/local/etc/raddb/modules/chap Mon Sep 26 09:18:24 2011 : Debug: including configuration file /usr/local/etc/raddb/modules/opendirectory Mon Sep 26 09:18:24 2011 : Debug: including configuration file /usr/local/etc/raddb/modules/pam Mon Sep 26 09:18:24 2011 : Debug: including configuration file /usr/local/etc/raddb/modules/realm Mon Sep 26 09:18:24 2011 : Debug: including configuration file /usr/local/etc/raddb/modules/checkval Mon Sep 26 09:18:24 2011 : Debug: including configuration file /usr/local/etc/raddb/modules/detail.log Mon Sep 26 09:18:24 2011 : Debug: including configuration file /usr/local/etc/raddb/modules/smbpasswd Mon Sep 26 09:18:24 2011 : Debug: including configuration file /usr/local/etc/raddb/modules/cui Mon Sep 26 09:18:24 2011 : Debug: including configuration file /usr/local/etc/raddb/modules/files Mon Sep 26 09:18:24 2011 : Debug: including configuration file /usr/local/etc/raddb/modules/etc_group Mon Sep 26 09:18:24 2011 : Debug: including configuration file /usr/local/etc/raddb/modules/redis Mon Sep 26 09:18:24 2011 : Debug: including configuration file /usr/local/etc/raddb/modules/passwd Mon Sep 26 09:18:24 2011 : Debug: including configuration file /usr/local/etc/raddb/modules/smsotp Mon Sep 26 09:18:24 2011 : Debug: including configuration file /usr/local/etc/raddb/eap.conf Mon Sep 26 09:18:24 2011 : Debug: including configuration file /usr/local/etc/raddb/policy.conf Mon Sep 26 09:18:24 2011 : Debug: including files in directory /usr/local/etc/raddb/sites-enabled/ Mon Sep 26 09:18:24 2011 : Debug: including configuration file /usr/local/etc/raddb/sites-enabled/default Mon Sep 26 09:18:24 2011 : Debug: including configuration file /usr/local/etc/raddb/sites-enabled/control-socket Mon Sep 26 09:18:24 2011 : Debug: including configuration file /usr/local/etc/raddb/sites-enabled/inner-tunnel Mon Sep 26 09:18:24 2011 : Debug: main { Mon Sep 26 09:18:24 2011 : Debug: allow_core_dumps = no Mon Sep 26 09:18:24 2011 : Debug: } Mon Sep 26 09:18:24 2011 : Debug: including dictionary file /usr/local/etc/raddb/dictionary Mon Sep 26 09:18:24 2011 : Debug: main { Mon Sep 26 09:18:24 2011 : Debug: name = "radiusd" Mon Sep 26 09:18:24 2011 : Debug: prefix = "/usr/local" Mon Sep 26 09:18:24 2011 : Debug: localstatedir = "/usr/local/var" Mon Sep 26 09:18:24 2011 : Debug: sbindir = "/usr/local/sbin" Mon Sep 26 09:18:24 2011 : Debug: logdir = "/usr/local/var/log/radius" Mon Sep 26 09:18:24 2011 : Debug: run_dir = "/usr/local/var/run/radiusd" Mon Sep 26 09:18:24 2011 : Debug: libdir = "/usr/local/lib" Mon Sep 26 09:18:24 2011 : Debug: radacctdir = "/usr/local/var/log/radius/radacct" Mon Sep 26 09:18:24 2011 : Debug: hostname_lookups = no Mon Sep 26 09:18:24 2011 : Debug: max_request_time = 30 Mon Sep 26 09:18:24 2011 : Debug: cleanup_delay = 5 Mon Sep 26 09:18:24 2011 : Debug: max_requests = 1024 Mon Sep 26 09:18:24 2011 : Debug: pidfile = "/usr/local/var/run/radiusd/radiusd.pid" Mon Sep 26 09:18:24 2011 : Debug: checkrad = "/usr/local/sbin/checkrad" Mon Sep 26 09:18:24 2011 : Debug: debug_level = 0 Mon Sep 26 09:18:24 2011 : Debug: proxy_requests = yes Mon Sep 26 09:18:24 2011 : Debug: log { Mon Sep 26 09:18:24 2011 : Debug: stripped_names = no Mon Sep 26 09:18:24 2011 : Debug: auth = no Mon Sep 26 09:18:24 2011 : Debug: auth_badpass = no Mon Sep 26 09:18:24 2011 : Debug: auth_goodpass = no Mon Sep 26 09:18:24 2011 : Debug: } Mon Sep 26 09:18:24 2011 : Debug: security { Mon Sep 26 09:18:24 2011 : Debug: max_attributes = 200 Mon Sep 26 09:18:24 2011 : Debug: reject_delay = 1 Mon Sep 26 09:18:24 2011 : Debug: status_server = yes Mon Sep 26 09:18:24 2011 : Debug: } Mon Sep 26 09:18:24 2011 : Debug: } Mon Sep 26 09:18:24 2011 : Debug: radiusd: #### Loading Realms and Home Servers #### Mon Sep 26 09:18:24 2011 : Debug: proxy server { Mon Sep 26 09:18:24 2011 : Debug: retry_delay = 5 Mon Sep 26 09:18:24 2011 : Debug: retry_count = 3 Mon Sep 26 09:18:24 2011 : Debug: default_fallback = no Mon Sep 26 09:18:24 2011 : Debug: dead_time = 120 Mon Sep 26 09:18:24 2011 : Debug: wake_all_if_all_dead = no Mon Sep 26 09:18:24 2011 : Debug: } Mon Sep 26 09:18:24 2011 : Debug: home_server localhost { Mon Sep 26 09:18:24 2011 : Debug: ipaddr = 127.0.0.1 Mon Sep 26 09:18:24 2011 : Debug: port = 1812 Mon Sep 26 09:18:24 2011 : Debug: type = "auth" Mon Sep 26 09:18:24 2011 : Debug: secret = "testing123" Mon Sep 26 09:18:24 2011 : Debug: response_window = 20 Mon Sep 26 09:18:24 2011 : Debug: max_outstanding = 65536 Mon Sep 26 09:18:24 2011 : Debug: require_message_authenticator = yes Mon Sep 26 09:18:24 2011 : Debug: zombie_period = 40 Mon Sep 26 09:18:24 2011 : Debug: status_check = "status-server" Mon Sep 26 09:18:24 2011 : Debug: ping_interval = 30 Mon Sep 26 09:18:24 2011 : Debug: check_interval = 30 Mon Sep 26 09:18:24 2011 : Debug: num_answers_to_alive = 3 Mon Sep 26 09:18:24 2011 : Debug: num_pings_to_alive = 3 Mon Sep 26 09:18:24 2011 : Debug: revive_interval = 120 Mon Sep 26 09:18:24 2011 : Debug: status_check_timeout = 4 Mon Sep 26 09:18:24 2011 : Debug: coa { Mon Sep 26 09:18:24 2011 : Debug: irt = 2 Mon Sep 26 09:18:24 2011 : Debug: mrt = 16 Mon Sep 26 09:18:24 2011 : Debug: mrc = 5 Mon Sep 26 09:18:24 2011 : Debug: mrd = 30 Mon Sep 26 09:18:24 2011 : Debug: } Mon Sep 26 09:18:24 2011 : Debug: } Mon Sep 26 09:18:24 2011 : Debug: home_server_pool my_auth_failover { Mon Sep 26 09:18:24 2011 : Debug: type = fail-over Mon Sep 26 09:18:24 2011 : Debug: home_server = localhost Mon Sep 26 09:18:24 2011 : Debug: } Mon Sep 26 09:18:24 2011 : Debug: realm example.com { Mon Sep 26 09:18:24 2011 : Debug: auth_pool = my_auth_failover Mon Sep 26 09:18:24 2011 : Debug: } Mon Sep 26 09:18:24 2011 : Debug: realm LOCAL { Mon Sep 26 09:18:24 2011 : Debug: } Mon Sep 26 09:18:24 2011 : Debug: realm ~.* { Mon Sep 26 09:18:24 2011 : Debug: } Mon Sep 26 09:18:24 2011 : Debug: radiusd: #### Loading Clients #### Mon Sep 26 09:18:24 2011 : Debug: client localhost { Mon Sep 26 09:18:24 2011 : Debug: ipaddr = 127.0.0.1 Mon Sep 26 09:18:24 2011 : Debug: require_message_authenticator = no Mon Sep 26 09:18:24 2011 : Debug: secret = "testing123" Mon Sep 26 09:18:24 2011 : Debug: nastype = "other" Mon Sep 26 09:18:24 2011 : Debug: } Mon Sep 26 09:18:24 2011 : Debug: client 10.0.0.0/8 { Mon Sep 26 09:18:24 2011 : Debug: require_message_authenticator = no Mon Sep 26 09:18:24 2011 : Debug: secret = "testing123" Mon Sep 26 09:18:24 2011 : Debug: } Mon Sep 26 09:18:24 2011 : Debug: radiusd: #### Instantiating modules #### Mon Sep 26 09:18:24 2011 : Debug: instantiate { Mon Sep 26 09:18:24 2011 : Debug: (Loaded rlm_exec, checking if it's valid) Mon Sep 26 09:18:24 2011 : Debug: Module: Linked to module rlm_exec Mon Sep 26 09:18:24 2011 : Debug: Module: Instantiating module "exec" from file /usr/local/etc/raddb/modules/exec Mon Sep 26 09:18:24 2011 : Debug: exec { Mon Sep 26 09:18:24 2011 : Debug: wait = no Mon Sep 26 09:18:24 2011 : Debug: input_pairs = "request" Mon Sep 26 09:18:24 2011 : Debug: shell_escape = yes Mon Sep 26 09:18:24 2011 : Debug: } Mon Sep 26 09:18:24 2011 : Debug: (Loaded rlm_expr, checking if it's valid) Mon Sep 26 09:18:24 2011 : Debug: Module: Linked to module rlm_expr Mon Sep 26 09:18:24 2011 : Debug: Module: Instantiating module "expr" from file /usr/local/etc/raddb/modules/expr Mon Sep 26 09:18:24 2011 : Debug: (Loaded rlm_expiration, checking if it's valid) Mon Sep 26 09:18:24 2011 : Debug: Module: Linked to module rlm_expiration Mon Sep 26 09:18:24 2011 : Debug: Module: Instantiating module "expiration" from file /usr/local/etc/raddb/modules/expiration Mon Sep 26 09:18:24 2011 : Debug: expiration { Mon Sep 26 09:18:24 2011 : Debug: reply-message = "Password Has Expired " Mon Sep 26 09:18:24 2011 : Debug: } Mon Sep 26 09:18:24 2011 : Debug: (Loaded rlm_logintime, checking if it's valid) Mon Sep 26 09:18:24 2011 : Debug: Module: Linked to module rlm_logintime Mon Sep 26 09:18:24 2011 : Debug: Module: Instantiating module "logintime" from file /usr/local/etc/raddb/modules/logintime Mon Sep 26 09:18:24 2011 : Debug: logintime { Mon Sep 26 09:18:24 2011 : Debug: reply-message = "You are calling outside your allowed timespan " Mon Sep 26 09:18:24 2011 : Debug: minimum-timeout = 60 Mon Sep 26 09:18:24 2011 : Debug: } Mon Sep 26 09:18:24 2011 : Debug: } Mon Sep 26 09:18:24 2011 : Debug: radiusd: #### Loading Virtual Servers #### Mon Sep 26 09:18:24 2011 : Debug: server { # from file /usr/local/etc/raddb/radiusd.conf Mon Sep 26 09:18:24 2011 : Debug: modules { Mon Sep 26 09:18:24 2011 : Debug: Module: Checking authenticate {...} for more modules to load Mon Sep 26 09:18:24 2011 : Debug: (Loaded rlm_pap, checking if it's valid) Mon Sep 26 09:18:24 2011 : Debug: Module: Linked to module rlm_pap Mon Sep 26 09:18:24 2011 : Debug: Module: Instantiating module "pap" from file /usr/local/etc/raddb/modules/pap Mon Sep 26 09:18:24 2011 : Debug: pap { Mon Sep 26 09:18:24 2011 : Debug: encryption_scheme = "auto" Mon Sep 26 09:18:24 2011 : Debug: auto_header = no Mon Sep 26 09:18:24 2011 : Debug: } Mon Sep 26 09:18:24 2011 : Debug: (Loaded rlm_chap, checking if it's valid) Mon Sep 26 09:18:24 2011 : Debug: Module: Linked to module rlm_chap Mon Sep 26 09:18:24 2011 : Debug: Module: Instantiating module "chap" from file /usr/local/etc/raddb/modules/chap Mon Sep 26 09:18:24 2011 : Debug: (Loaded rlm_mschap, checking if it's valid) Mon Sep 26 09:18:24 2011 : Debug: Module: Linked to module rlm_mschap Mon Sep 26 09:18:24 2011 : Debug: Module: Instantiating module "mschap" from file /usr/local/etc/raddb/modules/mschap Mon Sep 26 09:18:24 2011 : Debug: mschap { Mon Sep 26 09:18:24 2011 : Debug: use_mppe = no Mon Sep 26 09:18:24 2011 : Debug: require_encryption = no Mon Sep 26 09:18:24 2011 : Debug: require_strong = no Mon Sep 26 09:18:24 2011 : Debug: with_ntdomain_hack = no Mon Sep 26 09:18:24 2011 : Debug: allow_retry = yes Mon Sep 26 09:18:24 2011 : Debug: } Mon Sep 26 09:18:24 2011 : Debug: (Loaded rlm_digest, checking if it's valid) Mon Sep 26 09:18:24 2011 : Debug: Module: Linked to module rlm_digest Mon Sep 26 09:18:24 2011 : Debug: Module: Instantiating module "digest" from file /usr/local/etc/raddb/modules/digest Mon Sep 26 09:18:24 2011 : Debug: (Loaded rlm_unix, checking if it's valid) Mon Sep 26 09:18:24 2011 : Debug: Module: Linked to module rlm_unix Mon Sep 26 09:18:24 2011 : Debug: Module: Instantiating module "unix" from file /usr/local/etc/raddb/modules/unix Mon Sep 26 09:18:24 2011 : Debug: unix { Mon Sep 26 09:18:24 2011 : Debug: radwtmp = "/usr/local/var/log/radius/radwtmp" Mon Sep 26 09:18:24 2011 : Debug: } Mon Sep 26 09:18:24 2011 : Debug: (Loaded rlm_ldap, checking if it's valid) Mon Sep 26 09:18:24 2011 : Debug: Module: Linked to module rlm_ldap Mon Sep 26 09:18:24 2011 : Debug: Module: Instantiating module "ldap" from file /usr/local/etc/raddb/modules/ldap.orig Mon Sep 26 09:18:24 2011 : Debug: ldap { Mon Sep 26 09:18:24 2011 : Debug: server = "127.0.0.1" Mon Sep 26 09:18:24 2011 : Debug: port = 389 Mon Sep 26 09:18:24 2011 : Debug: password = "" Mon Sep 26 09:18:24 2011 : Debug: identity = "" Mon Sep 26 09:18:24 2011 : Debug: net_timeout = 1 Mon Sep 26 09:18:24 2011 : Debug: timeout = 4 Mon Sep 26 09:18:24 2011 : Debug: timelimit = 3 Mon Sep 26 09:18:24 2011 : Debug: tls_mode = no Mon Sep 26 09:18:24 2011 : Debug: start_tls = no Mon Sep 26 09:18:24 2011 : Debug: tls_require_cert = "allow" Mon Sep 26 09:18:24 2011 : Debug: tls { Mon Sep 26 09:18:24 2011 : Debug: start_tls = no Mon Sep 26 09:18:24 2011 : Debug: require_cert = "allow" Mon Sep 26 09:18:24 2011 : Debug: } Mon Sep 26 09:18:24 2011 : Debug: basedn = "ou=Users,dc=rcsd" Mon Sep 26 09:18:24 2011 : Debug: filter = "(uid=%{%{Stripped-User-Name}:-%{User-Name}})" Mon Sep 26 09:18:24 2011 : Debug: base_filter = "(objectclass=radiusprofile)" Mon Sep 26 09:18:24 2011 : Debug: auto_header = no Mon Sep 26 09:18:24 2011 : Debug: access_attr = "uid" Mon Sep 26 09:18:24 2011 : Debug: access_attr_used_for_allow = yes Mon Sep 26 09:18:24 2011 : Debug: groupname_attribute = "cn" Mon Sep 26 09:18:24 2011 : Debug: groupmembership_filter = "(|(&(objectClass=GroupOfNames)(member=%{Ldap-UserDn}))(&(objectClass=GroupOfUniqueNames)(uniquemember=%{Ldap-UserDn})))" Mon Sep 26 09:18:24 2011 : Debug: dictionary_mapping = "/usr/local/etc/raddb/ldap.attrmap" Mon Sep 26 09:18:24 2011 : Debug: ldap_debug = 0 Mon Sep 26 09:18:24 2011 : Debug: ldap_connections_number = 5 Mon Sep 26 09:18:24 2011 : Debug: compare_check_items = no Mon Sep 26 09:18:24 2011 : Debug: do_xlat = yes Mon Sep 26 09:18:24 2011 : Debug: set_auth_type = yes Mon Sep 26 09:18:24 2011 : Debug: } Mon Sep 26 09:18:24 2011 : Debug: rlm_ldap: Registering ldap_groupcmp for Ldap-Group Mon Sep 26 09:18:24 2011 : Debug: rlm_ldap: Registering ldap_xlat with xlat_name ldap Mon Sep 26 09:18:24 2011 : Debug: rlm_ldap: reading ldap<->radius mappings from file /usr/local/etc/raddb/ldap.attrmap Mon Sep 26 09:18:24 2011 : Debug: rlm_ldap: LDAP radiusCheckItem mapped to RADIUS $GENERIC$ Mon Sep 26 09:18:24 2011 : Debug: rlm_ldap: LDAP radiusReplyItem mapped to RADIUS $GENERIC$ Mon Sep 26 09:18:24 2011 : Debug: rlm_ldap: LDAP radiusAuthType mapped to RADIUS Auth-Type Mon Sep 26 09:18:24 2011 : Debug: rlm_ldap: LDAP radiusSimultaneousUse mapped to RADIUS Simultaneous-Use Mon Sep 26 09:18:24 2011 : Debug: rlm_ldap: LDAP radiusCalledStationId mapped to RADIUS Called-Station-Id Mon Sep 26 09:18:24 2011 : Debug: rlm_ldap: LDAP radiusCallingStationId mapped to RADIUS Calling-Station-Id Mon Sep 26 09:18:24 2011 : Debug: rlm_ldap: LDAP lmPassword mapped to RADIUS LM-Password Mon Sep 26 09:18:24 2011 : Debug: rlm_ldap: LDAP ntPassword mapped to RADIUS NT-Password Mon Sep 26 09:18:24 2011 : Debug: rlm_ldap: LDAP sambaLmPassword mapped to RADIUS LM-Password Mon Sep 26 09:18:24 2011 : Debug: rlm_ldap: LDAP sambaNtPassword mapped to RADIUS NT-Password Mon Sep 26 09:18:24 2011 : Debug: rlm_ldap: LDAP dBCSPwd mapped to RADIUS LM-Password Mon Sep 26 09:18:24 2011 : Debug: rlm_ldap: LDAP userPassword mapped to RADIUS Password-With-Header Mon Sep 26 09:18:24 2011 : Debug: rlm_ldap: LDAP acctFlags mapped to RADIUS SMB-Account-CTRL-TEXT Mon Sep 26 09:18:24 2011 : Debug: rlm_ldap: LDAP radiusExpiration mapped to RADIUS Expiration Mon Sep 26 09:18:24 2011 : Debug: rlm_ldap: LDAP radiusNASIpAddress mapped to RADIUS NAS-IP-Address Mon Sep 26 09:18:24 2011 : Debug: rlm_ldap: LDAP radiusServiceType mapped to RADIUS Service-Type Mon Sep 26 09:18:24 2011 : Debug: rlm_ldap: LDAP radiusFramedProtocol mapped to RADIUS Framed-Protocol Mon Sep 26 09:18:24 2011 : Debug: rlm_ldap: LDAP radiusFramedIPAddress mapped to RADIUS Framed-IP-Address Mon Sep 26 09:18:24 2011 : Debug: rlm_ldap: LDAP radiusFramedIPNetmask mapped to RADIUS Framed-IP-Netmask Mon Sep 26 09:18:24 2011 : Debug: rlm_ldap: LDAP radiusFramedRoute mapped to RADIUS Framed-Route Mon Sep 26 09:18:24 2011 : Debug: rlm_ldap: LDAP radiusFramedRouting mapped to RADIUS Framed-Routing Mon Sep 26 09:18:24 2011 : Debug: rlm_ldap: LDAP radiusFilterId mapped to RADIUS Filter-Id Mon Sep 26 09:18:24 2011 : Debug: rlm_ldap: LDAP radiusFramedMTU mapped to RADIUS Framed-MTU Mon Sep 26 09:18:24 2011 : Debug: rlm_ldap: LDAP radiusFramedCompression mapped to RADIUS Framed-Compression Mon Sep 26 09:18:24 2011 : Debug: rlm_ldap: LDAP radiusLoginIPHost mapped to RADIUS Login-IP-Host Mon Sep 26 09:18:24 2011 : Debug: rlm_ldap: LDAP radiusLoginService mapped to RADIUS Login-Service Mon Sep 26 09:18:24 2011 : Debug: rlm_ldap: LDAP radiusLoginTCPPort mapped to RADIUS Login-TCP-Port Mon Sep 26 09:18:24 2011 : Debug: rlm_ldap: LDAP radiusCallbackNumber mapped to RADIUS Callback-Number Mon Sep 26 09:18:24 2011 : Debug: rlm_ldap: LDAP radiusCallbackId mapped to RADIUS Callback-Id Mon Sep 26 09:18:24 2011 : Debug: rlm_ldap: LDAP radiusFramedIPXNetwork mapped to RADIUS Framed-IPX-Network Mon Sep 26 09:18:24 2011 : Debug: rlm_ldap: LDAP radiusClass mapped to RADIUS Class Mon Sep 26 09:18:24 2011 : Debug: rlm_ldap: LDAP radiusSessionTimeout mapped to RADIUS Session-Timeout Mon Sep 26 09:18:24 2011 : Debug: rlm_ldap: LDAP radiusIdleTimeout mapped to RADIUS Idle-Timeout Mon Sep 26 09:18:24 2011 : Debug: rlm_ldap: LDAP radiusTerminationAction mapped to RADIUS Termination-Action Mon Sep 26 09:18:24 2011 : Debug: rlm_ldap: LDAP radiusLoginLATService mapped to RADIUS Login-LAT-Service Mon Sep 26 09:18:24 2011 : Debug: rlm_ldap: LDAP radiusLoginLATNode mapped to RADIUS Login-LAT-Node Mon Sep 26 09:18:24 2011 : Debug: rlm_ldap: LDAP radiusLoginLATGroup mapped to RADIUS Login-LAT-Group Mon Sep 26 09:18:24 2011 : Debug: rlm_ldap: LDAP radiusFramedAppleTalkLink mapped to RADIUS Framed-AppleTalk-Link Mon Sep 26 09:18:24 2011 : Debug: rlm_ldap: LDAP radiusFramedAppleTalkNetwork mapped to RADIUS Framed-AppleTalk-Network Mon Sep 26 09:18:24 2011 : Debug: rlm_ldap: LDAP radiusFramedAppleTalkZone mapped to RADIUS Framed-AppleTalk-Zone Mon Sep 26 09:18:24 2011 : Debug: rlm_ldap: LDAP radiusPortLimit mapped to RADIUS Port-Limit Mon Sep 26 09:18:24 2011 : Debug: rlm_ldap: LDAP radiusLoginLATPort mapped to RADIUS Login-LAT-Port Mon Sep 26 09:18:24 2011 : Debug: rlm_ldap: LDAP radiusReplyMessage mapped to RADIUS Reply-Message Mon Sep 26 09:18:24 2011 : Debug: rlm_ldap: LDAP radiusTunnelType mapped to RADIUS Tunnel-Type Mon Sep 26 09:18:24 2011 : Debug: rlm_ldap: LDAP radiusTunnelMediumType mapped to RADIUS Tunnel-Medium-Type Mon Sep 26 09:18:24 2011 : Debug: rlm_ldap: LDAP radiusTunnelPrivateGroupId mapped to RADIUS Tunnel-Private-Group-Id Mon Sep 26 09:18:24 2011 : Debug: conns: 0x161fbb0 Mon Sep 26 09:18:24 2011 : Debug: (Loaded rlm_eap, checking if it's valid) Mon Sep 26 09:18:24 2011 : Debug: Module: Linked to module rlm_eap Mon Sep 26 09:18:24 2011 : Debug: Module: Instantiating module "eap" from file /usr/local/etc/raddb/eap.conf Mon Sep 26 09:18:24 2011 : Debug: eap { Mon Sep 26 09:18:24 2011 : Debug: default_eap_type = "md5" Mon Sep 26 09:18:24 2011 : Debug: timer_expire = 60 Mon Sep 26 09:18:24 2011 : Debug: ignore_unknown_eap_types = no Mon Sep 26 09:18:24 2011 : Debug: cisco_accounting_username_bug = no Mon Sep 26 09:18:24 2011 : Debug: max_sessions = 4096 Mon Sep 26 09:18:24 2011 : Debug: } Mon Sep 26 09:18:24 2011 : Debug: Module: Linked to sub-module rlm_eap_md5 Mon Sep 26 09:18:24 2011 : Debug: Module: Instantiating eap-md5 Mon Sep 26 09:18:24 2011 : Debug: Module: Linked to sub-module rlm_eap_leap Mon Sep 26 09:18:24 2011 : Debug: Module: Instantiating eap-leap Mon Sep 26 09:18:24 2011 : Debug: Module: Linked to sub-module rlm_eap_gtc Mon Sep 26 09:18:24 2011 : Debug: Module: Instantiating eap-gtc Mon Sep 26 09:18:24 2011 : Debug: gtc { Mon Sep 26 09:18:24 2011 : Debug: challenge = "Password: " Mon Sep 26 09:18:24 2011 : Debug: auth_type = "PAP" Mon Sep 26 09:18:24 2011 : Debug: } Mon Sep 26 09:18:24 2011 : Debug: Module: Linked to sub-module rlm_eap_tls Mon Sep 26 09:18:24 2011 : Debug: Module: Instantiating eap-tls Mon Sep 26 09:18:24 2011 : Debug: tls { Mon Sep 26 09:18:24 2011 : Debug: rsa_key_exchange = no Mon Sep 26 09:18:24 2011 : Debug: dh_key_exchange = yes Mon Sep 26 09:18:24 2011 : Debug: rsa_key_length = 512 Mon Sep 26 09:18:24 2011 : Debug: dh_key_length = 512 Mon Sep 26 09:18:24 2011 : Debug: verify_depth = 0 Mon Sep 26 09:18:24 2011 : Debug: CA_path = "/usr/local/etc/raddb/certs" Mon Sep 26 09:18:24 2011 : Debug: pem_file_type = yes Mon Sep 26 09:18:24 2011 : Debug: private_key_file = "/usr/local/etc/raddb/certs/server.pem" Mon Sep 26 09:18:24 2011 : Debug: certificate_file = "/usr/local/etc/raddb/certs/server.pem" Mon Sep 26 09:18:24 2011 : Debug: CA_file = "/usr/local/etc/raddb/certs/ca.pem" Mon Sep 26 09:18:24 2011 : Debug: private_key_password = "whatever" Mon Sep 26 09:18:24 2011 : Debug: dh_file = "/usr/local/etc/raddb/certs/dh" Mon Sep 26 09:18:24 2011 : Debug: random_file = "/usr/local/etc/raddb/certs/random" Mon Sep 26 09:18:24 2011 : Debug: fragment_size = 1024 Mon Sep 26 09:18:24 2011 : Debug: include_length = yes Mon Sep 26 09:18:24 2011 : Debug: check_crl = no Mon Sep 26 09:18:24 2011 : Debug: cipher_list = "DEFAULT" Mon Sep 26 09:18:24 2011 : Debug: make_cert_command = "/usr/local/etc/raddb/certs/bootstrap" Mon Sep 26 09:18:24 2011 : Debug: cache { Mon Sep 26 09:18:24 2011 : Debug: enable = no Mon Sep 26 09:18:24 2011 : Debug: lifetime = 24 Mon Sep 26 09:18:24 2011 : Debug: max_entries = 255 Mon Sep 26 09:18:24 2011 : Debug: } Mon Sep 26 09:18:24 2011 : Debug: verify { Mon Sep 26 09:18:24 2011 : Debug: } Mon Sep 26 09:18:24 2011 : Debug: ocsp { Mon Sep 26 09:18:24 2011 : Debug: enable = no Mon Sep 26 09:18:24 2011 : Debug: override_cert_url = yes Mon Sep 26 09:18:24 2011 : Debug: url = "http://127.0.0.1/ocsp/" Mon Sep 26 09:18:24 2011 : Debug: } Mon Sep 26 09:18:24 2011 : Debug: } Mon Sep 26 09:18:24 2011 : Debug: Module: Linked to sub-module rlm_eap_ttls Mon Sep 26 09:18:24 2011 : Debug: Module: Instantiating eap-ttls Mon Sep 26 09:18:24 2011 : Debug: ttls { Mon Sep 26 09:18:24 2011 : Debug: default_eap_type = "md5" Mon Sep 26 09:18:24 2011 : Debug: copy_request_to_tunnel = no Mon Sep 26 09:18:24 2011 : Debug: use_tunneled_reply = no Mon Sep 26 09:18:24 2011 : Debug: virtual_server = "inner-tunnel" Mon Sep 26 09:18:24 2011 : Debug: include_length = yes Mon Sep 26 09:18:24 2011 : Debug: } Mon Sep 26 09:18:24 2011 : Debug: Module: Linked to sub-module rlm_eap_peap Mon Sep 26 09:18:24 2011 : Debug: Module: Instantiating eap-peap Mon Sep 26 09:18:24 2011 : Debug: peap { Mon Sep 26 09:18:24 2011 : Debug: default_eap_type = "mschapv2" Mon Sep 26 09:18:24 2011 : Debug: copy_request_to_tunnel = yes Mon Sep 26 09:18:24 2011 : Debug: use_tunneled_reply = yes Mon Sep 26 09:18:24 2011 : Debug: proxy_tunneled_request_as_eap = no Mon Sep 26 09:18:24 2011 : Debug: virtual_server = "inner-tunnel" Mon Sep 26 09:18:24 2011 : Debug: soh = no Mon Sep 26 09:18:24 2011 : Debug: } Mon Sep 26 09:18:24 2011 : Debug: Module: Linked to sub-module rlm_eap_mschapv2 Mon Sep 26 09:18:24 2011 : Debug: Module: Instantiating eap-mschapv2 Mon Sep 26 09:18:24 2011 : Debug: mschapv2 { Mon Sep 26 09:18:24 2011 : Debug: with_ntdomain_hack = no Mon Sep 26 09:18:24 2011 : Debug: send_error = no Mon Sep 26 09:18:24 2011 : Debug: } Mon Sep 26 09:18:24 2011 : Debug: Module: Checking authorize {...} for more modules to load Mon Sep 26 09:18:24 2011 : Debug: (Loaded rlm_preprocess, checking if it's valid) Mon Sep 26 09:18:24 2011 : Debug: Module: Linked to module rlm_preprocess Mon Sep 26 09:18:24 2011 : Debug: Module: Instantiating module "preprocess" from file /usr/local/etc/raddb/modules/preprocess Mon Sep 26 09:18:24 2011 : Debug: preprocess { Mon Sep 26 09:18:24 2011 : Debug: huntgroups = "/usr/local/etc/raddb/huntgroups" Mon Sep 26 09:18:24 2011 : Debug: hints = "/usr/local/etc/raddb/hints" Mon Sep 26 09:18:24 2011 : Debug: with_ascend_hack = no Mon Sep 26 09:18:24 2011 : Debug: ascend_channels_per_line = 23 Mon Sep 26 09:18:24 2011 : Debug: with_ntdomain_hack = no Mon Sep 26 09:18:24 2011 : Debug: with_specialix_jetstream_hack = no Mon Sep 26 09:18:24 2011 : Debug: with_cisco_vsa_hack = no Mon Sep 26 09:18:24 2011 : Debug: with_alvarion_vsa_hack = no Mon Sep 26 09:18:24 2011 : Debug: } Mon Sep 26 09:18:24 2011 : Debug: (Loaded rlm_realm, checking if it's valid) Mon Sep 26 09:18:24 2011 : Debug: Module: Linked to module rlm_realm Mon Sep 26 09:18:24 2011 : Debug: Module: Instantiating module "ntdomain" from file /usr/local/etc/raddb/modules/realm Mon Sep 26 09:18:24 2011 : Debug: realm ntdomain { Mon Sep 26 09:18:24 2011 : Debug: format = "prefix" Mon Sep 26 09:18:24 2011 : Debug: delimiter = "\" Mon Sep 26 09:18:24 2011 : Debug: ignore_default = no Mon Sep 26 09:18:24 2011 : Debug: ignore_null = no Mon Sep 26 09:18:24 2011 : Debug: } Mon Sep 26 09:18:24 2011 : Debug: (Loaded rlm_files, checking if it's valid) Mon Sep 26 09:18:24 2011 : Debug: Module: Linked to module rlm_files Mon Sep 26 09:18:24 2011 : Debug: Module: Instantiating module "files" from file /usr/local/etc/raddb/modules/files Mon Sep 26 09:18:24 2011 : Debug: files { Mon Sep 26 09:18:24 2011 : Debug: usersfile = "/usr/local/etc/raddb/users" Mon Sep 26 09:18:24 2011 : Debug: acctusersfile = "/usr/local/etc/raddb/acct_users" Mon Sep 26 09:18:24 2011 : Debug: preproxy_usersfile = "/usr/local/etc/raddb/preproxy_users" Mon Sep 26 09:18:24 2011 : Debug: compat = "no" Mon Sep 26 09:18:24 2011 : Debug: } Mon Sep 26 09:18:24 2011 : Debug: Module: Checking preacct {...} for more modules to load Mon Sep 26 09:18:24 2011 : Debug: (Loaded rlm_acct_unique, checking if it's valid) Mon Sep 26 09:18:24 2011 : Debug: Module: Linked to module rlm_acct_unique Mon Sep 26 09:18:24 2011 : Debug: Module: Instantiating module "acct_unique" from file /usr/local/etc/raddb/modules/acct_unique Mon Sep 26 09:18:24 2011 : Debug: acct_unique { Mon Sep 26 09:18:24 2011 : Debug: key = "User-Name, Acct-Session-Id, NAS-IP-Address, Client-IP-Address, NAS-Port" Mon Sep 26 09:18:24 2011 : Debug: } Mon Sep 26 09:18:24 2011 : Debug: Module: Checking accounting {...} for more modules to load Mon Sep 26 09:18:24 2011 : Debug: (Loaded rlm_detail, checking if it's valid) Mon Sep 26 09:18:24 2011 : Debug: Module: Linked to module rlm_detail Mon Sep 26 09:18:24 2011 : Debug: Module: Instantiating module "detail" from file /usr/local/etc/raddb/modules/detail Mon Sep 26 09:18:24 2011 : Debug: detail { Mon Sep 26 09:18:24 2011 : Debug: detailfile = "/usr/local/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d" Mon Sep 26 09:18:24 2011 : Debug: header = "%t" Mon Sep 26 09:18:24 2011 : Debug: detailperm = 384 Mon Sep 26 09:18:24 2011 : Debug: dirperm = 493 Mon Sep 26 09:18:24 2011 : Debug: locking = no Mon Sep 26 09:18:24 2011 : Debug: log_packet_header = no Mon Sep 26 09:18:24 2011 : Debug: } Mon Sep 26 09:18:24 2011 : Debug: (Loaded rlm_radutmp, checking if it's valid) Mon Sep 26 09:18:24 2011 : Debug: Module: Linked to module rlm_radutmp Mon Sep 26 09:18:24 2011 : Debug: Module: Instantiating module "radutmp" from file /usr/local/etc/raddb/modules/radutmp Mon Sep 26 09:18:24 2011 : Debug: radutmp { Mon Sep 26 09:18:24 2011 : Debug: filename = "/usr/local/var/log/radius/radutmp" Mon Sep 26 09:18:24 2011 : Debug: username = "%{User-Name}" Mon Sep 26 09:18:24 2011 : Debug: case_sensitive = yes Mon Sep 26 09:18:24 2011 : Debug: check_with_nas = yes Mon Sep 26 09:18:24 2011 : Debug: perm = 384 Mon Sep 26 09:18:24 2011 : Debug: callerid = yes Mon Sep 26 09:18:24 2011 : Debug: } Mon Sep 26 09:18:24 2011 : Debug: (Loaded rlm_attr_filter, checking if it's valid) Mon Sep 26 09:18:24 2011 : Debug: Module: Linked to module rlm_attr_filter Mon Sep 26 09:18:24 2011 : Debug: Module: Instantiating module "attr_filter.accounting_response" from file /usr/local/etc/raddb/modules/attr_filter Mon Sep 26 09:18:24 2011 : Debug: attr_filter attr_filter.accounting_response { Mon Sep 26 09:18:24 2011 : Debug: attrsfile = "/usr/local/etc/raddb/attrs.accounting_response" Mon Sep 26 09:18:24 2011 : Debug: key = "%{User-Name}" Mon Sep 26 09:18:24 2011 : Debug: } Mon Sep 26 09:18:24 2011 : Debug: Module: Checking session {...} for more modules to load Mon Sep 26 09:18:24 2011 : Debug: Module: Checking post-proxy {...} for more modules to load Mon Sep 26 09:18:24 2011 : Debug: Module: Checking post-auth {...} for more modules to load Mon Sep 26 09:18:24 2011 : Debug: Module: Instantiating module "attr_filter.access_reject" from file /usr/local/etc/raddb/modules/attr_filter Mon Sep 26 09:18:24 2011 : Debug: attr_filter attr_filter.access_reject { Mon Sep 26 09:18:24 2011 : Debug: attrsfile = "/usr/local/etc/raddb/attrs.access_reject" Mon Sep 26 09:18:24 2011 : Debug: key = "%{User-Name}" Mon Sep 26 09:18:24 2011 : Debug: } Mon Sep 26 09:18:24 2011 : Debug: } # modules Mon Sep 26 09:18:24 2011 : Debug: } # server Mon Sep 26 09:18:24 2011 : Debug: server inner-tunnel { # from file /usr/local/etc/raddb/sites-enabled/inner-tunnel Mon Sep 26 09:18:24 2011 : Debug: modules { Mon Sep 26 09:18:24 2011 : Debug: Module: Checking authenticate {...} for more modules to load Mon Sep 26 09:18:24 2011 : Debug: Module: Checking authorize {...} for more modules to load Mon Sep 26 09:18:24 2011 : Debug: Module: Checking session {...} for more modules to load Mon Sep 26 09:18:24 2011 : Debug: Module: Checking post-proxy {...} for more modules to load Mon Sep 26 09:18:24 2011 : Debug: Module: Checking post-auth {...} for more modules to load Mon Sep 26 09:18:24 2011 : Debug: } # modules Mon Sep 26 09:18:24 2011 : Debug: } # server Mon Sep 26 09:18:24 2011 : Debug: radiusd: #### Opening IP addresses and Ports #### Mon Sep 26 09:18:24 2011 : Debug: listen { Mon Sep 26 09:18:24 2011 : Debug: type = "auth" Mon Sep 26 09:18:24 2011 : Debug: ipaddr = * Mon Sep 26 09:18:24 2011 : Debug: port = 0 Mon Sep 26 09:18:24 2011 : Debug: } Mon Sep 26 09:18:24 2011 : Debug: listen { Mon Sep 26 09:18:24 2011 : Debug: type = "acct" Mon Sep 26 09:18:24 2011 : Debug: ipaddr = * Mon Sep 26 09:18:24 2011 : Debug: port = 0 Mon Sep 26 09:18:24 2011 : Debug: } Mon Sep 26 09:18:24 2011 : Debug: listen { Mon Sep 26 09:18:24 2011 : Debug: type = "control" Mon Sep 26 09:18:24 2011 : Debug: listen { Mon Sep 26 09:18:24 2011 : Debug: socket = "/usr/local/var/run/radiusd/radiusd.sock" Mon Sep 26 09:18:24 2011 : Debug: } Mon Sep 26 09:18:24 2011 : Debug: } Mon Sep 26 09:18:24 2011 : Debug: listen { Mon Sep 26 09:18:24 2011 : Debug: type = "auth" Mon Sep 26 09:18:24 2011 : Debug: ipaddr = 127.0.0.1 Mon Sep 26 09:18:24 2011 : Debug: port = 18120 Mon Sep 26 09:18:24 2011 : Debug: } Mon Sep 26 09:18:24 2011 : Info: ... adding new socket proxy address * port 57019 Mon Sep 26 09:18:24 2011 : Debug: Listening on authentication address * port 1645 Mon Sep 26 09:18:24 2011 : Debug: Listening on accounting address * port 1646 Mon Sep 26 09:18:24 2011 : Debug: Listening on command file /usr/local/var/run/radiusd/radiusd.sock Mon Sep 26 09:18:24 2011 : Debug: Listening on authentication address 127.0.0.1 port 18120 as server inner-tunnel Mon Sep 26 09:18:24 2011 : Debug: Listening on proxy address * port 1647 Mon Sep 26 09:18:24 2011 : Info: Ready to process requests. rad_recv: Access-Request packet from host 10.0.14.36 port 1645, id=142, length=137 User-Name = "RC24558\\jojo" Framed-MTU = 1400 Called-Station-Id = "0013.5ffa.57f0" Calling-Station-Id = "0013.ceca.3fb6" Service-Type = Login-User Message-Authenticator = 0x10e3b4b217bfc29c1475f84171e6dbcb EAP-Message = 0x0202001101524332343535385c6a6f6a6f NAS-Port-Type = Wireless-802.11 NAS-Port = 15159 NAS-IP-Address = 10.0.14.36 NAS-Identifier = "ap" Mon Sep 26 09:18:30 2011 : Info: # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default Mon Sep 26 09:18:30 2011 : Info: +- entering group authorize {...} Mon Sep 26 09:18:30 2011 : Info: ++[preprocess] returns ok Mon Sep 26 09:18:30 2011 : Info: ++[chap] returns noop Mon Sep 26 09:18:30 2011 : Info: ++[mschap] returns noop Mon Sep 26 09:18:30 2011 : Info: ++[digest] returns noop Mon Sep 26 09:18:30 2011 : Info: [ntdomain] Looking up realm "RC24558" for User-Name = "RC24558\jojo" Mon Sep 26 09:18:30 2011 : Info: [ntdomain] Found realm "~.*" Mon Sep 26 09:18:30 2011 : Info: [ntdomain] Adding Stripped-User-Name = "jojo" Mon Sep 26 09:18:30 2011 : Info: [ntdomain] Adding Realm = "RC24558" Mon Sep 26 09:18:30 2011 : Info: [ntdomain] Authentication realm is LOCAL. Mon Sep 26 09:18:30 2011 : Info: ++[ntdomain] returns ok Mon Sep 26 09:18:30 2011 : Info: [eap] EAP packet type response id 2 length 17 Mon Sep 26 09:18:30 2011 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation Mon Sep 26 09:18:30 2011 : Info: ++[eap] returns updated Mon Sep 26 09:18:30 2011 : Info: ++[files] returns noop Mon Sep 26 09:18:30 2011 : Info: [ldap] performing user authorization for jojo Mon Sep 26 09:18:30 2011 : Info: [ldap] expand: %{Stripped-User-Name} -> jojo Mon Sep 26 09:18:30 2011 : Info: [ldap] expand: (uid=%{%{Stripped-User-Name}:-%{User-Name}}) -> (uid=jojo) Mon Sep 26 09:18:30 2011 : Info: [ldap] expand: ou=Users,dc=rcsd -> ou=Users,dc=rcsd Mon Sep 26 09:18:30 2011 : Debug: [ldap] ldap_get_conn: Checking Id: 0 Mon Sep 26 09:18:30 2011 : Debug: [ldap] ldap_get_conn: Got Id: 0 Mon Sep 26 09:18:30 2011 : Debug: [ldap] attempting LDAP reconnection Mon Sep 26 09:18:30 2011 : Debug: [ldap] (re)connect to 127.0.0.1:389, authentication 0 Mon Sep 26 09:18:30 2011 : Debug: [ldap] bind as / to 127.0.0.1:389 Mon Sep 26 09:18:30 2011 : Debug: [ldap] waiting for bind result ... Mon Sep 26 09:18:30 2011 : Debug: [ldap] Bind was successful Mon Sep 26 09:18:30 2011 : Debug: [ldap] performing search in ou=Users,dc=rcsd, with filter (uid=jojo) Mon Sep 26 09:18:30 2011 : Info: [ldap] checking if remote access for jojo is allowed by uid Mon Sep 26 09:18:30 2011 : Info: [ldap] looking for check items in directory... Mon Sep 26 09:18:30 2011 : Debug: [ldap] userPassword -> Password-With-Header == "{SSHA}II8f7AGFYlC1KCv9i1ciQO5U9qNG1RrG" Mon Sep 26 09:18:30 2011 : Debug: [ldap] sambaNtPassword -> NT-Password == 0x3530354139323739434644324639344336353839383035353143464445373335 Mon Sep 26 09:18:30 2011 : Info: [ldap] looking for reply items in directory... Mon Sep 26 09:18:30 2011 : Info: [ldap] user jojo authorized to use remote access Mon Sep 26 09:18:30 2011 : Debug: [ldap] ldap_release_conn: Release Id: 0 Mon Sep 26 09:18:30 2011 : Info: ++[ldap] returns ok Mon Sep 26 09:18:30 2011 : Info: ++[expiration] returns noop Mon Sep 26 09:18:30 2011 : Info: ++[logintime] returns noop Mon Sep 26 09:18:30 2011 : Info: [pap] Normalizing NT-Password from hex encoding Mon Sep 26 09:18:30 2011 : Info: [pap] Normalizing SSHA1-Password from base64 encoding Mon Sep 26 09:18:30 2011 : Info: [pap] WARNING: Auth-Type already set. Not setting to PAP Mon Sep 26 09:18:30 2011 : Info: ++[pap] returns noop Mon Sep 26 09:18:30 2011 : Info: Found Auth-Type = EAP Mon Sep 26 09:18:30 2011 : Info: # Executing group from file /usr/local/etc/raddb/sites-enabled/default Mon Sep 26 09:18:30 2011 : Info: +- entering group authenticate {...} Mon Sep 26 09:18:30 2011 : Info: [eap] EAP Identity Mon Sep 26 09:18:30 2011 : Info: [eap] processing type md5 Mon Sep 26 09:18:30 2011 : Debug: rlm_eap_md5: Issuing Challenge Mon Sep 26 09:18:30 2011 : Info: ++[eap] returns handled Sending Access-Challenge of id 142 to 10.0.14.36 port 1645 EAP-Message = 0x010300160410198263449a37508833162c8ac44e5a51 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x012a67f1012963b59928657b4c6fcae7 Mon Sep 26 09:18:30 2011 : Info: Finished request 0. Mon Sep 26 09:18:30 2011 : Debug: Going to the next request Mon Sep 26 09:18:30 2011 : Debug: Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 10.0.14.36 port 1645, id=143, length=144 User-Name = "RC24558\\jojo" Framed-MTU = 1400 Called-Station-Id = "0013.5ffa.57f0" Calling-Station-Id = "0013.ceca.3fb6" Service-Type = Login-User Message-Authenticator = 0x9c67381470e7af73494b8c783844ccf4 EAP-Message = 0x020300060319 NAS-Port-Type = Wireless-802.11 NAS-Port = 15159 State = 0x012a67f1012963b59928657b4c6fcae7 NAS-IP-Address = 10.0.14.36 NAS-Identifier = "ap" Mon Sep 26 09:18:30 2011 : Info: # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default Mon Sep 26 09:18:30 2011 : Info: +- entering group authorize {...} Mon Sep 26 09:18:30 2011 : Info: ++[preprocess] returns ok Mon Sep 26 09:18:30 2011 : Info: ++[chap] returns noop Mon Sep 26 09:18:30 2011 : Info: ++[mschap] returns noop Mon Sep 26 09:18:30 2011 : Info: ++[digest] returns noop Mon Sep 26 09:18:30 2011 : Info: [ntdomain] Looking up realm "RC24558" for User-Name = "RC24558\jojo" Mon Sep 26 09:18:30 2011 : Info: [ntdomain] Found realm "~.*" Mon Sep 26 09:18:30 2011 : Info: [ntdomain] Adding Stripped-User-Name = "jojo" Mon Sep 26 09:18:30 2011 : Info: [ntdomain] Adding Realm = "RC24558" Mon Sep 26 09:18:30 2011 : Info: [ntdomain] Authentication realm is LOCAL. Mon Sep 26 09:18:30 2011 : Info: ++[ntdomain] returns ok Mon Sep 26 09:18:30 2011 : Info: [eap] EAP packet type response id 3 length 6 Mon Sep 26 09:18:30 2011 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation Mon Sep 26 09:18:30 2011 : Info: ++[eap] returns updated Mon Sep 26 09:18:30 2011 : Info: ++[files] returns noop Mon Sep 26 09:18:30 2011 : Info: [ldap] performing user authorization for jojo Mon Sep 26 09:18:30 2011 : Info: [ldap] expand: %{Stripped-User-Name} -> jojo Mon Sep 26 09:18:30 2011 : Info: [ldap] expand: (uid=%{%{Stripped-User-Name}:-%{User-Name}}) -> (uid=jojo) Mon Sep 26 09:18:30 2011 : Info: [ldap] expand: ou=Users,dc=rcsd -> ou=Users,dc=rcsd Mon Sep 26 09:18:30 2011 : Debug: [ldap] ldap_get_conn: Checking Id: 0 Mon Sep 26 09:18:30 2011 : Debug: [ldap] ldap_get_conn: Got Id: 0 Mon Sep 26 09:18:30 2011 : Debug: [ldap] performing search in ou=Users,dc=rcsd, with filter (uid=jojo) Mon Sep 26 09:18:30 2011 : Info: [ldap] checking if remote access for jojo is allowed by uid Mon Sep 26 09:18:30 2011 : Info: [ldap] looking for check items in directory... Mon Sep 26 09:18:30 2011 : Debug: [ldap] userPassword -> Password-With-Header == "{SSHA}II8f7AGFYlC1KCv9i1ciQO5U9qNG1RrG" Mon Sep 26 09:18:30 2011 : Debug: [ldap] sambaNtPassword -> NT-Password == 0x3530354139323739434644324639344336353839383035353143464445373335 Mon Sep 26 09:18:30 2011 : Info: [ldap] looking for reply items in directory... Mon Sep 26 09:18:30 2011 : Info: [ldap] user jojo authorized to use remote access Mon Sep 26 09:18:30 2011 : Debug: [ldap] ldap_release_conn: Release Id: 0 Mon Sep 26 09:18:30 2011 : Info: ++[ldap] returns ok Mon Sep 26 09:18:30 2011 : Info: ++[expiration] returns noop Mon Sep 26 09:18:30 2011 : Info: ++[logintime] returns noop Mon Sep 26 09:18:30 2011 : Info: [pap] Normalizing NT-Password from hex encoding Mon Sep 26 09:18:30 2011 : Info: [pap] Normalizing SSHA1-Password from base64 encoding Mon Sep 26 09:18:30 2011 : Info: [pap] WARNING: Auth-Type already set. Not setting to PAP Mon Sep 26 09:18:30 2011 : Info: ++[pap] returns noop Mon Sep 26 09:18:30 2011 : Info: Found Auth-Type = EAP Mon Sep 26 09:18:30 2011 : Info: # Executing group from file /usr/local/etc/raddb/sites-enabled/default Mon Sep 26 09:18:30 2011 : Info: +- entering group authenticate {...} Mon Sep 26 09:18:30 2011 : Info: [eap] Request found, released from the list Mon Sep 26 09:18:30 2011 : Info: [eap] EAP NAK Mon Sep 26 09:18:30 2011 : Info: [eap] EAP-NAK asked for EAP-Type/peap Mon Sep 26 09:18:30 2011 : Info: [eap] processing type tls Mon Sep 26 09:18:30 2011 : Info: [tls] Initiate Mon Sep 26 09:18:30 2011 : Info: [tls] Start returned 1 Mon Sep 26 09:18:30 2011 : Info: ++[eap] returns handled Sending Access-Challenge of id 143 to 10.0.14.36 port 1645 EAP-Message = 0x010400061920 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x012a67f1002e7eb59928657b4c6fcae7 Mon Sep 26 09:18:30 2011 : Info: Finished request 1. Mon Sep 26 09:18:30 2011 : Debug: Going to the next request Mon Sep 26 09:18:30 2011 : Debug: Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 10.0.14.36 port 1645, id=144, length=225 User-Name = "RC24558\\jojo" Framed-MTU = 1400 Called-Station-Id = "0013.5ffa.57f0" Calling-Station-Id = "0013.ceca.3fb6" Service-Type = Login-User Message-Authenticator = 0xa8235a77b76131d43120d86ed61dc623 EAP-Message = 0x0204005719800000004d16030100480100004403014e80897a12cbc8fd5ed3f727d61573e9cc4e6203f7c622352466a033db02b6d700001600040005000a0009006400620003000600130012006301000005ff01000100 NAS-Port-Type = Wireless-802.11 NAS-Port = 15159 State = 0x012a67f1002e7eb59928657b4c6fcae7 NAS-IP-Address = 10.0.14.36 NAS-Identifier = "ap" Mon Sep 26 09:18:30 2011 : Info: # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default Mon Sep 26 09:18:30 2011 : Info: +- entering group authorize {...} Mon Sep 26 09:18:30 2011 : Info: ++[preprocess] returns ok Mon Sep 26 09:18:30 2011 : Info: ++[chap] returns noop Mon Sep 26 09:18:30 2011 : Info: ++[mschap] returns noop Mon Sep 26 09:18:30 2011 : Info: ++[digest] returns noop Mon Sep 26 09:18:30 2011 : Info: [ntdomain] Looking up realm "RC24558" for User-Name = "RC24558\jojo" Mon Sep 26 09:18:30 2011 : Info: [ntdomain] Found realm "~.*" Mon Sep 26 09:18:30 2011 : Info: [ntdomain] Adding Stripped-User-Name = "jojo" Mon Sep 26 09:18:30 2011 : Info: [ntdomain] Adding Realm = "RC24558" Mon Sep 26 09:18:30 2011 : Info: [ntdomain] Authentication realm is LOCAL. Mon Sep 26 09:18:30 2011 : Info: ++[ntdomain] returns ok Mon Sep 26 09:18:30 2011 : Info: [eap] EAP packet type response id 4 length 87 Mon Sep 26 09:18:30 2011 : Info: [eap] Continuing tunnel setup. Mon Sep 26 09:18:30 2011 : Info: ++[eap] returns ok Mon Sep 26 09:18:30 2011 : Info: Found Auth-Type = EAP Mon Sep 26 09:18:30 2011 : Info: # Executing group from file /usr/local/etc/raddb/sites-enabled/default Mon Sep 26 09:18:30 2011 : Info: +- entering group authenticate {...} Mon Sep 26 09:18:30 2011 : Info: [eap] Request found, released from the list Mon Sep 26 09:18:30 2011 : Info: [eap] EAP/peap Mon Sep 26 09:18:30 2011 : Info: [eap] processing type peap Mon Sep 26 09:18:30 2011 : Info: [peap] processing EAP-TLS Mon Sep 26 09:18:30 2011 : Debug: TLS Length 77 Mon Sep 26 09:18:30 2011 : Info: [peap] Length Included Mon Sep 26 09:18:30 2011 : Info: [peap] eaptls_verify returned 11 Mon Sep 26 09:18:30 2011 : Info: [peap] (other): before/accept initialization Mon Sep 26 09:18:30 2011 : Info: [peap] TLS_accept: before/accept initialization Mon Sep 26 09:18:30 2011 : Info: [peap] <<< TLS 1.0 Handshake [length 0048], ClientHello Mon Sep 26 09:18:30 2011 : Info: [peap] TLS_accept: SSLv3 read client hello A Mon Sep 26 09:18:30 2011 : Info: [peap] >>> TLS 1.0 Handshake [length 0031], ServerHello Mon Sep 26 09:18:30 2011 : Info: [peap] TLS_accept: SSLv3 write server hello A Mon Sep 26 09:18:30 2011 : Info: [peap] >>> TLS 1.0 Handshake [length 085e], Certificate Mon Sep 26 09:18:30 2011 : Info: [peap] TLS_accept: SSLv3 write certificate A Mon Sep 26 09:18:30 2011 : Info: [peap] >>> TLS 1.0 Handshake [length 0004], ServerHelloDone Mon Sep 26 09:18:30 2011 : Info: [peap] TLS_accept: SSLv3 write server done A Mon Sep 26 09:18:30 2011 : Info: [peap] TLS_accept: SSLv3 flush data Mon Sep 26 09:18:30 2011 : Info: [peap] TLS_accept: Need to read more data: SSLv3 read client certificate A Mon Sep 26 09:18:30 2011 : Debug: In SSL Handshake Phase Mon Sep 26 09:18:30 2011 : Debug: In SSL Accept mode Mon Sep 26 09:18:30 2011 : Info: [peap] eaptls_process returned 13 Mon Sep 26 09:18:30 2011 : Info: [peap] EAPTLS_HANDLED Mon Sep 26 09:18:30 2011 : Info: ++[eap] returns handled Sending Access-Challenge of id 144 to 10.0.14.36 port 1645 EAP-Message = 0x0105040019c0000008a216030100310200002d03014e8089b6d200a56ce809bc4878ede8000777623ae97bde467adc01c47ff58f1d000004000005ff01000100160301085e0b00085a0008570003a6308203a23082028aa003020102020101300d06092a864886f70d0101040500308193310b3009060355040613024652310f300d060355040813065261646975733112301006035504071309536f6d65776865726531153013060355040a130c4578616d706c6520496e632e3120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d312630240603550403131d4578616d706c65204365727469666963617465204175 EAP-Message = 0x74686f72697479301e170d3131303930383138353830365a170d3132303930373138353830365a307c310b3009060355040613024652310f300d0603550408130652616469757331153013060355040a130c4578616d706c6520496e632e312330210603550403131a4578616d706c65205365727665722043657274696669636174653120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d30820122300d06092a864886f70d01010105000382010f003082010a0282010100e4ff2f9b63285ff75dbd766d7b3d6f087510d315e13c260b2c73d9b6ef5f9966798c8523aa2af3ee6a9ec7415443d931da84d2b8748f86 EAP-Message = 0x86960fc69424d37fc2a181928e203f2a3b3d653c9e625b691000f251e4f33cc2df588d2e97d0cbee194f4d28ef1d4fbf2d45de86c1539c4baa226348f896b8d103e805ff2eadb5f7d12bbbce8308c30b65295e4b56509402814dc4827efab54361ebb7b3a305fee7de90abb8d5bf4af7a12f36bf0e3e67c82177bd36a5f2527f30d82ff44ae6fe3febc256b3d3add88598e45e2b55727a7430008e4f3cad10cb60269fd17ccf0da53a4cea51030ed76d356eb9f605b1b42b0df8b2513c08602a1bbcb1f88cc91db99f0203010001a317301530130603551d25040c300a06082b06010505070301300d06092a864886f70d010104050003820101008a0f EAP-Message = 0x27d8bc135a3012b7af033199562b962b4215261539176b55de2f8f5c42cd532d91f018c916ac168ae3b298884d3ce7767d078fbc9c1ed73bf973789f6ed5f73e6e5a39e4ae65f00794878c4f8e9ee2e7aa8607549cf40b3eef7e647e8d2dc2aefaffa98b7e8a25201dba8fa1db8e27a78fba99310a51fca5ca1609dcb736299095e7eb9d3f771732586c5894ca51091af5bb8c2069eff219f8ddec540ac1e848ea74e6a62a17eba925b8b3d07761ecfcb191385fbca8712a68176879646958e908e137258b571de151877e8ced15366ef571de2d47af6ffe66951bf56052576b9e99ab438b667df45a878cf99e3a82918fdf26f52001c59cf0e509b20e EAP-Message = 0x740004ab308204a73082038f Message-Authenticator = 0x00000000000000000000000000000000 State = 0x012a67f1032f7eb59928657b4c6fcae7 Mon Sep 26 09:18:30 2011 : Info: Finished request 2. Mon Sep 26 09:18:30 2011 : Debug: Going to the next request Mon Sep 26 09:18:30 2011 : Debug: Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 10.0.14.36 port 1645, id=145, length=144 User-Name = "RC24558\\jojo" Framed-MTU = 1400 Called-Station-Id = "0013.5ffa.57f0" Calling-Station-Id = "0013.ceca.3fb6" Service-Type = Login-User Message-Authenticator = 0x128a1e759f92c4248df2d9ae3b901010 EAP-Message = 0x020500061900 NAS-Port-Type = Wireless-802.11 NAS-Port = 15159 State = 0x012a67f1032f7eb59928657b4c6fcae7 NAS-IP-Address = 10.0.14.36 NAS-Identifier = "ap" Mon Sep 26 09:18:30 2011 : Info: # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default Mon Sep 26 09:18:30 2011 : Info: +- entering group authorize {...} Mon Sep 26 09:18:30 2011 : Info: ++[preprocess] returns ok Mon Sep 26 09:18:30 2011 : Info: ++[chap] returns noop Mon Sep 26 09:18:30 2011 : Info: ++[mschap] returns noop Mon Sep 26 09:18:30 2011 : Info: ++[digest] returns noop Mon Sep 26 09:18:30 2011 : Info: [ntdomain] Looking up realm "RC24558" for User-Name = "RC24558\jojo" Mon Sep 26 09:18:30 2011 : Info: [ntdomain] Found realm "~.*" Mon Sep 26 09:18:30 2011 : Info: [ntdomain] Adding Stripped-User-Name = "jojo" Mon Sep 26 09:18:30 2011 : Info: [ntdomain] Adding Realm = "RC24558" Mon Sep 26 09:18:30 2011 : Info: [ntdomain] Authentication realm is LOCAL. Mon Sep 26 09:18:30 2011 : Info: ++[ntdomain] returns ok Mon Sep 26 09:18:30 2011 : Info: [eap] EAP packet type response id 5 length 6 Mon Sep 26 09:18:30 2011 : Info: [eap] Continuing tunnel setup. Mon Sep 26 09:18:30 2011 : Info: ++[eap] returns ok Mon Sep 26 09:18:30 2011 : Info: Found Auth-Type = EAP Mon Sep 26 09:18:30 2011 : Info: # Executing group from file /usr/local/etc/raddb/sites-enabled/default Mon Sep 26 09:18:30 2011 : Info: +- entering group authenticate {...} Mon Sep 26 09:18:30 2011 : Info: [eap] Request found, released from the list Mon Sep 26 09:18:30 2011 : Info: [eap] EAP/peap Mon Sep 26 09:18:30 2011 : Info: [eap] processing type peap Mon Sep 26 09:18:30 2011 : Info: [peap] processing EAP-TLS Mon Sep 26 09:18:30 2011 : Info: [peap] Received TLS ACK Mon Sep 26 09:18:30 2011 : Info: [peap] ACK handshake fragment handler Mon Sep 26 09:18:30 2011 : Info: [peap] eaptls_verify returned 1 Mon Sep 26 09:18:30 2011 : Info: [peap] eaptls_process returned 13 Mon Sep 26 09:18:30 2011 : Info: [peap] EAPTLS_HANDLED Mon Sep 26 09:18:30 2011 : Info: ++[eap] returns handled Sending Access-Challenge of id 145 to 10.0.14.36 port 1645 EAP-Message = 0x010603fc1940a003020102020900ce34e34810f39fc0300d06092a864886f70d0101050500308193310b3009060355040613024652310f300d060355040813065261646975733112301006035504071309536f6d65776865726531153013060355040a130c4578616d706c6520496e632e3120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d312630240603550403131d4578616d706c6520436572746966696361746520417574686f72697479301e170d3131303930383138353830365a170d3132303930373138353830365a308193310b3009060355040613024652310f300d0603550408130652616469757331 EAP-Message = 0x12301006035504071309536f6d65776865726531153013060355040a130c4578616d706c6520496e632e3120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d312630240603550403131d4578616d706c6520436572746966696361746520417574686f7269747930820122300d06092a864886f70d01010105000382010f003082010a0282010100b723badaa3886218ee4187d712939b8d9c92a1747b5acf4e14c5f11317a6dfbd29dee31432e58738753625f088e369c2ca2601379d1872d9fe39c47b147b0cb3c99c2465b48197d14613b504e737d9db9a5025b3a7708febef7cb625c3ae10439010f185838ed1f1 EAP-Message = 0x155a2d77de562a531f26214cedadb853d434e24cc404a4c19462d9ff224c7d7b6c5b18bb81b184cce1a81227cd1e241a984792a1cf8d310db502276f22ef198f7ab809d851057aa8b43ee236ece276ff117793806fa0c2f25b93de8c050ba5a4febdc2f3fa6d4dca02fb569db96a98bf37f3dd1f3e20968368c999cd148fb7bfe3c9c4458141ef310dc34a64c5b5843db0f893bc87f09af10203010001a381fb3081f8301d0603551d0e0416041459226d7362797c622ef4b17635053c962f52b3a03081c80603551d230481c03081bd801459226d7362797c622ef4b17635053c962f52b3a0a18199a48196308193310b300906035504061302465231 EAP-Message = 0x0f300d060355040813065261646975733112301006035504071309536f6d65776865726531153013060355040a130c4578616d706c6520496e632e3120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d312630240603550403131d4578616d706c6520436572746966696361746520417574686f72697479820900ce34e34810f39fc0300c0603551d13040530030101ff300d06092a864886f70d010105050003820101001fe877f4ce00c41b0030442314a8ade36598b7ced780957a685113406cfac979cd8c9e246f734481ef32f2a3bad3874491d02ad2f77ac2196062ec11d01f92b356e3fc2471fb808423d319 EAP-Message = 0x17f2104db9d2c871 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x012a67f1022c7eb59928657b4c6fcae7 Mon Sep 26 09:18:30 2011 : Info: Finished request 3. Mon Sep 26 09:18:30 2011 : Debug: Going to the next request Mon Sep 26 09:18:30 2011 : Debug: Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 10.0.14.36 port 1645, id=146, length=144 User-Name = "RC24558\\jojo" Framed-MTU = 1400 Called-Station-Id = "0013.5ffa.57f0" Calling-Station-Id = "0013.ceca.3fb6" Service-Type = Login-User Message-Authenticator = 0x5dcb0fdadd08239b637df5b5c08de666 EAP-Message = 0x020600061900 NAS-Port-Type = Wireless-802.11 NAS-Port = 15159 State = 0x012a67f1022c7eb59928657b4c6fcae7 NAS-IP-Address = 10.0.14.36 NAS-Identifier = "ap" Mon Sep 26 09:18:30 2011 : Info: # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default Mon Sep 26 09:18:30 2011 : Info: +- entering group authorize {...} Mon Sep 26 09:18:30 2011 : Info: ++[preprocess] returns ok Mon Sep 26 09:18:30 2011 : Info: ++[chap] returns noop Mon Sep 26 09:18:30 2011 : Info: ++[mschap] returns noop Mon Sep 26 09:18:30 2011 : Info: ++[digest] returns noop Mon Sep 26 09:18:30 2011 : Info: [ntdomain] Looking up realm "RC24558" for User-Name = "RC24558\jojo" Mon Sep 26 09:18:30 2011 : Info: [ntdomain] Found realm "~.*" Mon Sep 26 09:18:30 2011 : Info: [ntdomain] Adding Stripped-User-Name = "jojo" Mon Sep 26 09:18:30 2011 : Info: [ntdomain] Adding Realm = "RC24558" Mon Sep 26 09:18:30 2011 : Info: [ntdomain] Authentication realm is LOCAL. Mon Sep 26 09:18:30 2011 : Info: ++[ntdomain] returns ok Mon Sep 26 09:18:30 2011 : Info: [eap] EAP packet type response id 6 length 6 Mon Sep 26 09:18:30 2011 : Info: [eap] Continuing tunnel setup. Mon Sep 26 09:18:30 2011 : Info: ++[eap] returns ok Mon Sep 26 09:18:30 2011 : Info: Found Auth-Type = EAP Mon Sep 26 09:18:30 2011 : Info: # Executing group from file /usr/local/etc/raddb/sites-enabled/default Mon Sep 26 09:18:30 2011 : Info: +- entering group authenticate {...} Mon Sep 26 09:18:30 2011 : Info: [eap] Request found, released from the list Mon Sep 26 09:18:30 2011 : Info: [eap] EAP/peap Mon Sep 26 09:18:30 2011 : Info: [eap] processing type peap Mon Sep 26 09:18:30 2011 : Info: [peap] processing EAP-TLS Mon Sep 26 09:18:30 2011 : Info: [peap] Received TLS ACK Mon Sep 26 09:18:30 2011 : Info: [peap] ACK handshake fragment handler Mon Sep 26 09:18:30 2011 : Info: [peap] eaptls_verify returned 1 Mon Sep 26 09:18:30 2011 : Info: [peap] eaptls_process returned 13 Mon Sep 26 09:18:30 2011 : Info: [peap] EAPTLS_HANDLED Mon Sep 26 09:18:30 2011 : Info: ++[eap] returns handled Sending Access-Challenge of id 146 to 10.0.14.36 port 1645 EAP-Message = 0x010700bc19009b313887ca4ccd81e9b42c703b87cf0cb1a4c272474f5a83338897b5c4e7a1dfc901ff799406f67d5b33b9b7b1e885725bee7990b3b2764128241a615c1d37a72517b68c38ad8bc2887ec4b362da8c99fef4626ce3f6e4d019e59664f5ad2897fa091235485ce5f8d2788ff35f73770308ea8f9d04a328ff068f0d292c32e50d5973e0cf33f195ebde3905c5550e1379a37d43217172b170a59816d6d58036e437d4e23a1eda7fec65a01d7e4616030100040e000000 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x012a67f1052d7eb59928657b4c6fcae7 Mon Sep 26 09:18:30 2011 : Info: Finished request 4. Mon Sep 26 09:18:30 2011 : Debug: Going to the next request Mon Sep 26 09:18:30 2011 : Debug: Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 10.0.14.36 port 1645, id=147, length=460 User-Name = "RC24558\\jojo" Framed-MTU = 1400 Called-Station-Id = "0013.5ffa.57f0" Calling-Station-Id = "0013.ceca.3fb6" Service-Type = Login-User Message-Authenticator = 0xc799de7ca48efe8b95ad15af01fff452 EAP-Message = 0x020701401980000001361603010106100001020100de9f66dd971d4ed1b91c46d438543181542bab29b2fe26f6cb50bc6115cf0befcc1b651ea327f021c28fe6cedfef51a3c052d3ba6dff7b0901304d1c597b5186fb0733758dbc5ee7f43c5b8e74a1409c275000add661280c070580bda42cdf0690daa59af6646b012404f778dd95c1c7a9317fae4f54c30e726a2cb0db65cea0f00d2e38797080483befd59e037ef8bc75ec0f93f88c082082878eb2b35ef7ecbe269bbde2f966b6bc4c4c9b6fb43f66d9275958d5c35e2904efc246bda614fb404a9fa1b4783e694302a3cdc6574cc0c14d6023b87d97f84e4e40229fdc9e55d85dd4ce240ffda5 EAP-Message = 0xa95a8ba5362a1af6b5beecf13629299908568d459af0ad141403010001011603010020d146e56e8ece6e02c646c8fa54c95fa9aae4e46c6fc11589c5f8b530d893dc90 NAS-Port-Type = Wireless-802.11 NAS-Port = 15159 State = 0x012a67f1052d7eb59928657b4c6fcae7 NAS-IP-Address = 10.0.14.36 NAS-Identifier = "ap" Mon Sep 26 09:18:30 2011 : Info: # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default Mon Sep 26 09:18:30 2011 : Info: +- entering group authorize {...} Mon Sep 26 09:18:30 2011 : Info: ++[preprocess] returns ok Mon Sep 26 09:18:30 2011 : Info: ++[chap] returns noop Mon Sep 26 09:18:30 2011 : Info: ++[mschap] returns noop Mon Sep 26 09:18:30 2011 : Info: ++[digest] returns noop Mon Sep 26 09:18:30 2011 : Info: [ntdomain] Looking up realm "RC24558" for User-Name = "RC24558\jojo" Mon Sep 26 09:18:30 2011 : Info: [ntdomain] Found realm "~.*" Mon Sep 26 09:18:30 2011 : Info: [ntdomain] Adding Stripped-User-Name = "jojo" Mon Sep 26 09:18:30 2011 : Info: [ntdomain] Adding Realm = "RC24558" Mon Sep 26 09:18:30 2011 : Info: [ntdomain] Authentication realm is LOCAL. Mon Sep 26 09:18:30 2011 : Info: ++[ntdomain] returns ok Mon Sep 26 09:18:30 2011 : Info: [eap] EAP packet type response id 7 length 253 Mon Sep 26 09:18:30 2011 : Info: [eap] Continuing tunnel setup. Mon Sep 26 09:18:30 2011 : Info: ++[eap] returns ok Mon Sep 26 09:18:30 2011 : Info: Found Auth-Type = EAP Mon Sep 26 09:18:30 2011 : Info: # Executing group from file /usr/local/etc/raddb/sites-enabled/default Mon Sep 26 09:18:30 2011 : Info: +- entering group authenticate {...} Mon Sep 26 09:18:30 2011 : Info: [eap] Request found, released from the list Mon Sep 26 09:18:30 2011 : Info: [eap] EAP/peap Mon Sep 26 09:18:30 2011 : Info: [eap] processing type peap Mon Sep 26 09:18:30 2011 : Info: [peap] processing EAP-TLS Mon Sep 26 09:18:30 2011 : Debug: TLS Length 310 Mon Sep 26 09:18:30 2011 : Info: [peap] Length Included Mon Sep 26 09:18:30 2011 : Info: [peap] eaptls_verify returned 11 Mon Sep 26 09:18:30 2011 : Info: [peap] <<< TLS 1.0 Handshake [length 0106], ClientKeyExchange Mon Sep 26 09:18:30 2011 : Info: [peap] TLS_accept: SSLv3 read client key exchange A Mon Sep 26 09:18:30 2011 : Info: [peap] <<< TLS 1.0 ChangeCipherSpec [length 0001] Mon Sep 26 09:18:30 2011 : Info: [peap] <<< TLS 1.0 Handshake [length 0010], Finished Mon Sep 26 09:18:30 2011 : Info: [peap] TLS_accept: SSLv3 read finished A Mon Sep 26 09:18:30 2011 : Info: [peap] >>> TLS 1.0 ChangeCipherSpec [length 0001] Mon Sep 26 09:18:30 2011 : Info: [peap] TLS_accept: SSLv3 write change cipher spec A Mon Sep 26 09:18:30 2011 : Info: [peap] >>> TLS 1.0 Handshake [length 0010], Finished Mon Sep 26 09:18:30 2011 : Info: [peap] TLS_accept: SSLv3 write finished A Mon Sep 26 09:18:30 2011 : Info: [peap] TLS_accept: SSLv3 flush data Mon Sep 26 09:18:30 2011 : Info: [peap] (other): SSL negotiation finished successfully Mon Sep 26 09:18:30 2011 : Debug: SSL Connection Established Mon Sep 26 09:18:30 2011 : Info: [peap] eaptls_process returned 13 Mon Sep 26 09:18:30 2011 : Info: [peap] EAPTLS_HANDLED Mon Sep 26 09:18:30 2011 : Info: ++[eap] returns handled Sending Access-Challenge of id 147 to 10.0.14.36 port 1645 EAP-Message = 0x01080031190014030100010116030100200cb7df9ff454fef7de6975717eb852b3df0a34f046ae775c57eeace36c41cf9f Message-Authenticator = 0x00000000000000000000000000000000 State = 0x012a67f104227eb59928657b4c6fcae7 Mon Sep 26 09:18:30 2011 : Info: Finished request 5. Mon Sep 26 09:18:30 2011 : Debug: Going to the next request Mon Sep 26 09:18:30 2011 : Debug: Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 10.0.14.36 port 1645, id=148, length=144 User-Name = "RC24558\\jojo" Framed-MTU = 1400 Called-Station-Id = "0013.5ffa.57f0" Calling-Station-Id = "0013.ceca.3fb6" Service-Type = Login-User Message-Authenticator = 0x55f77ac864bb3e2f4673aba670ab63ee EAP-Message = 0x020800061900 NAS-Port-Type = Wireless-802.11 NAS-Port = 15159 State = 0x012a67f104227eb59928657b4c6fcae7 NAS-IP-Address = 10.0.14.36 NAS-Identifier = "ap" Mon Sep 26 09:18:30 2011 : Info: # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default Mon Sep 26 09:18:30 2011 : Info: +- entering group authorize {...} Mon Sep 26 09:18:30 2011 : Info: ++[preprocess] returns ok Mon Sep 26 09:18:30 2011 : Info: ++[chap] returns noop Mon Sep 26 09:18:30 2011 : Info: ++[mschap] returns noop Mon Sep 26 09:18:30 2011 : Info: ++[digest] returns noop Mon Sep 26 09:18:30 2011 : Info: [ntdomain] Looking up realm "RC24558" for User-Name = "RC24558\jojo" Mon Sep 26 09:18:30 2011 : Info: [ntdomain] Found realm "~.*" Mon Sep 26 09:18:30 2011 : Info: [ntdomain] Adding Stripped-User-Name = "jojo" Mon Sep 26 09:18:30 2011 : Info: [ntdomain] Adding Realm = "RC24558" Mon Sep 26 09:18:30 2011 : Info: [ntdomain] Authentication realm is LOCAL. Mon Sep 26 09:18:30 2011 : Info: ++[ntdomain] returns ok Mon Sep 26 09:18:30 2011 : Info: [eap] EAP packet type response id 8 length 6 Mon Sep 26 09:18:30 2011 : Info: [eap] Continuing tunnel setup. Mon Sep 26 09:18:30 2011 : Info: ++[eap] returns ok Mon Sep 26 09:18:30 2011 : Info: Found Auth-Type = EAP Mon Sep 26 09:18:30 2011 : Info: # Executing group from file /usr/local/etc/raddb/sites-enabled/default Mon Sep 26 09:18:30 2011 : Info: +- entering group authenticate {...} Mon Sep 26 09:18:30 2011 : Info: [eap] Request found, released from the list Mon Sep 26 09:18:30 2011 : Info: [eap] EAP/peap Mon Sep 26 09:18:30 2011 : Info: [eap] processing type peap Mon Sep 26 09:18:30 2011 : Info: [peap] processing EAP-TLS Mon Sep 26 09:18:30 2011 : Info: [peap] Received TLS ACK Mon Sep 26 09:18:30 2011 : Info: [peap] ACK handshake is finished Mon Sep 26 09:18:30 2011 : Info: [peap] eaptls_verify returned 3 Mon Sep 26 09:18:30 2011 : Info: [peap] eaptls_process returned 3 Mon Sep 26 09:18:30 2011 : Info: [peap] EAPTLS_SUCCESS Mon Sep 26 09:18:30 2011 : Info: [peap] Session established. Decoding tunneled attributes. Mon Sep 26 09:18:30 2011 : Info: [peap] Peap state TUNNEL ESTABLISHED Mon Sep 26 09:18:30 2011 : Info: ++[eap] returns handled Sending Access-Challenge of id 148 to 10.0.14.36 port 1645 EAP-Message = 0x010900201900170301001551fd4d3fc3aae6886ccf2a0c4d7fb35a9ef0f18bcf Message-Authenticator = 0x00000000000000000000000000000000 State = 0x012a67f107237eb59928657b4c6fcae7 Mon Sep 26 09:18:30 2011 : Info: Finished request 6. Mon Sep 26 09:18:30 2011 : Debug: Going to the next request Mon Sep 26 09:18:30 2011 : Debug: Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 10.0.14.36 port 1645, id=149, length=178 User-Name = "RC24558\\jojo" Framed-MTU = 1400 Called-Station-Id = "0013.5ffa.57f0" Calling-Station-Id = "0013.ceca.3fb6" Service-Type = Login-User Message-Authenticator = 0x01057955c90b0ae8feb7658bc951fa8a EAP-Message = 0x020900281900170301001d3bcbbd9b33590050d24629d34fc88147b36f185759dd406a6d3223893b NAS-Port-Type = Wireless-802.11 NAS-Port = 15159 State = 0x012a67f107237eb59928657b4c6fcae7 NAS-IP-Address = 10.0.14.36 NAS-Identifier = "ap" Mon Sep 26 09:18:30 2011 : Info: # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default Mon Sep 26 09:18:30 2011 : Info: +- entering group authorize {...} Mon Sep 26 09:18:30 2011 : Info: ++[preprocess] returns ok Mon Sep 26 09:18:30 2011 : Info: ++[chap] returns noop Mon Sep 26 09:18:30 2011 : Info: ++[mschap] returns noop Mon Sep 26 09:18:30 2011 : Info: ++[digest] returns noop Mon Sep 26 09:18:30 2011 : Info: [ntdomain] Looking up realm "RC24558" for User-Name = "RC24558\jojo" Mon Sep 26 09:18:30 2011 : Info: [ntdomain] Found realm "~.*" Mon Sep 26 09:18:30 2011 : Info: [ntdomain] Adding Stripped-User-Name = "jojo" Mon Sep 26 09:18:30 2011 : Info: [ntdomain] Adding Realm = "RC24558" Mon Sep 26 09:18:30 2011 : Info: [ntdomain] Authentication realm is LOCAL. Mon Sep 26 09:18:30 2011 : Info: ++[ntdomain] returns ok Mon Sep 26 09:18:30 2011 : Info: [eap] EAP packet type response id 9 length 40 Mon Sep 26 09:18:30 2011 : Info: [eap] Continuing tunnel setup. Mon Sep 26 09:18:30 2011 : Info: ++[eap] returns ok Mon Sep 26 09:18:30 2011 : Info: Found Auth-Type = EAP Mon Sep 26 09:18:30 2011 : Info: # Executing group from file /usr/local/etc/raddb/sites-enabled/default Mon Sep 26 09:18:30 2011 : Info: +- entering group authenticate {...} Mon Sep 26 09:18:30 2011 : Info: [eap] Request found, released from the list Mon Sep 26 09:18:30 2011 : Info: [eap] EAP/peap Mon Sep 26 09:18:30 2011 : Info: [eap] processing type peap Mon Sep 26 09:18:30 2011 : Info: [peap] processing EAP-TLS Mon Sep 26 09:18:30 2011 : Info: [peap] eaptls_verify returned 7 Mon Sep 26 09:18:30 2011 : Info: [peap] Done initial handshake Mon Sep 26 09:18:30 2011 : Info: [peap] eaptls_process returned 7 Mon Sep 26 09:18:30 2011 : Info: [peap] EAPTLS_OK Mon Sep 26 09:18:30 2011 : Info: [peap] Session established. Decoding tunneled attributes. Mon Sep 26 09:18:30 2011 : Info: [peap] Peap state WAITING FOR INNER IDENTITY Mon Sep 26 09:18:30 2011 : Info: [peap] Identity - RC24558\jojo Mon Sep 26 09:18:30 2011 : Info: [peap] Got inner identity 'RC24558\jojo' Mon Sep 26 09:18:30 2011 : Info: [peap] Setting default EAP type for tunneled EAP session. Mon Sep 26 09:18:30 2011 : Info: [peap] Got tunneled request EAP-Message = 0x0209001101524332343535385c6a6f6a6f server { Mon Sep 26 09:18:30 2011 : Info: [peap] Setting User-Name to RC24558\jojo Sending tunneled request EAP-Message = 0x0209001101524332343535385c6a6f6a6f FreeRADIUS-Proxied-To = 127.0.0.1 User-Name = "RC24558\\jojo" Framed-MTU = 1400 Called-Station-Id = "0013.5ffa.57f0" Calling-Station-Id = "0013.ceca.3fb6" Service-Type = Login-User NAS-Port-Type = Wireless-802.11 NAS-Port = 15159 NAS-IP-Address = 10.0.14.36 NAS-Identifier = "ap" server inner-tunnel { Mon Sep 26 09:18:30 2011 : Info: # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/inner-tunnel Mon Sep 26 09:18:30 2011 : Info: +- entering group authorize {...} Mon Sep 26 09:18:30 2011 : Info: ++[mschap] returns noop Mon Sep 26 09:18:30 2011 : Info: [ntdomain] Looking up realm "RC24558" for User-Name = "RC24558\jojo" Mon Sep 26 09:18:30 2011 : Info: [ntdomain] Found realm "~.*" Mon Sep 26 09:18:30 2011 : Info: [ntdomain] Adding Stripped-User-Name = "jojo" Mon Sep 26 09:18:30 2011 : Info: [ntdomain] Adding Realm = "RC24558" Mon Sep 26 09:18:30 2011 : Info: [ntdomain] Authentication realm is LOCAL. Mon Sep 26 09:18:30 2011 : Info: ++[ntdomain] returns ok Mon Sep 26 09:18:30 2011 : Info: ++[control] returns ok Mon Sep 26 09:18:30 2011 : Info: [eap] EAP packet type response id 9 length 17 Mon Sep 26 09:18:30 2011 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation Mon Sep 26 09:18:30 2011 : Info: ++[eap] returns updated Mon Sep 26 09:18:30 2011 : Info: ++[files] returns noop Mon Sep 26 09:18:30 2011 : Info: [ldap] performing user authorization for jojo Mon Sep 26 09:18:30 2011 : Info: [ldap] expand: %{Stripped-User-Name} -> jojo Mon Sep 26 09:18:30 2011 : Info: [ldap] expand: (uid=%{%{Stripped-User-Name}:-%{User-Name}}) -> (uid=jojo) Mon Sep 26 09:18:30 2011 : Info: [ldap] expand: ou=Users,dc=rcsd -> ou=Users,dc=rcsd Mon Sep 26 09:18:30 2011 : Debug: [ldap] ldap_get_conn: Checking Id: 0 Mon Sep 26 09:18:30 2011 : Debug: [ldap] ldap_get_conn: Got Id: 0 Mon Sep 26 09:18:30 2011 : Debug: [ldap] performing search in ou=Users,dc=rcsd, with filter (uid=jojo) Mon Sep 26 09:18:30 2011 : Info: [ldap] checking if remote access for jojo is allowed by uid Mon Sep 26 09:18:30 2011 : Info: [ldap] looking for check items in directory... Mon Sep 26 09:18:30 2011 : Debug: [ldap] userPassword -> Password-With-Header == "{SSHA}II8f7AGFYlC1KCv9i1ciQO5U9qNG1RrG" Mon Sep 26 09:18:30 2011 : Debug: [ldap] sambaNtPassword -> NT-Password == 0x3530354139323739434644324639344336353839383035353143464445373335 Mon Sep 26 09:18:30 2011 : Info: [ldap] looking for reply items in directory... Mon Sep 26 09:18:30 2011 : Info: [ldap] user jojo authorized to use remote access Mon Sep 26 09:18:30 2011 : Debug: [ldap] ldap_release_conn: Release Id: 0 Mon Sep 26 09:18:30 2011 : Info: ++[ldap] returns ok Mon Sep 26 09:18:30 2011 : Info: ++[expiration] returns noop Mon Sep 26 09:18:30 2011 : Info: ++[logintime] returns noop Mon Sep 26 09:18:30 2011 : Info: [pap] Normalizing NT-Password from hex encoding Mon Sep 26 09:18:30 2011 : Info: [pap] Normalizing SSHA1-Password from base64 encoding Mon Sep 26 09:18:30 2011 : Info: [pap] WARNING: Auth-Type already set. Not setting to PAP Mon Sep 26 09:18:30 2011 : Info: ++[pap] returns noop Mon Sep 26 09:18:30 2011 : Info: Found Auth-Type = EAP Mon Sep 26 09:18:30 2011 : Info: # Executing group from file /usr/local/etc/raddb/sites-enabled/inner-tunnel Mon Sep 26 09:18:30 2011 : Info: +- entering group authenticate {...} Mon Sep 26 09:18:30 2011 : Info: [eap] EAP Identity Mon Sep 26 09:18:30 2011 : Info: [eap] processing type mschapv2 Mon Sep 26 09:18:30 2011 : Debug: rlm_eap_mschapv2: Issuing Challenge Mon Sep 26 09:18:30 2011 : Info: ++[eap] returns handled } # server inner-tunnel Mon Sep 26 09:18:30 2011 : Info: [peap] Got tunneled reply code 11 EAP-Message = 0x010a00261a010a00211072e844cfde1393faca4e9cd22d2517ed524332343535385c6a6f6a6f Message-Authenticator = 0x00000000000000000000000000000000 State = 0x2e162f4f2e1c35eccc0848a7af8693ad Mon Sep 26 09:18:30 2011 : Info: [peap] Got tunneled reply RADIUS code 11 EAP-Message = 0x010a00261a010a00211072e844cfde1393faca4e9cd22d2517ed524332343535385c6a6f6a6f Message-Authenticator = 0x00000000000000000000000000000000 State = 0x2e162f4f2e1c35eccc0848a7af8693ad Mon Sep 26 09:18:30 2011 : Info: [peap] Got tunneled Access-Challenge Mon Sep 26 09:18:30 2011 : Info: ++[eap] returns handled Sending Access-Challenge of id 149 to 10.0.14.36 port 1645 EAP-Message = 0x010a003d190017030100321792f8992de0d798730efec62ecb0740acf93865478ea83c9e6336c3a52bc2c11e40d6531d4d1afe9162657c37e759c13ec7 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x012a67f106207eb59928657b4c6fcae7 Mon Sep 26 09:18:30 2011 : Info: Finished request 7. Mon Sep 26 09:18:30 2011 : Debug: Going to the next request Mon Sep 26 09:18:30 2011 : Debug: Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 10.0.14.36 port 1645, id=150, length=224 User-Name = "RC24558\\jojo" Framed-MTU = 1400 Called-Station-Id = "0013.5ffa.57f0" Calling-Station-Id = "0013.ceca.3fb6" Service-Type = Login-User Message-Authenticator = 0xdf7adb26e9e89137de8fc21d4f1a395e EAP-Message = 0x020a00561900170301004b2364a5c487226a0de3b29cfeb4f9c7af4014e404e93a4810495e3cb659e0cafaedd49db8fea2b6db56099cdc0984a91bd22ea44305786530fabb32ef8ae3b02d63052ca72896168659b5dd NAS-Port-Type = Wireless-802.11 NAS-Port = 15159 State = 0x012a67f106207eb59928657b4c6fcae7 NAS-IP-Address = 10.0.14.36 NAS-Identifier = "ap" Mon Sep 26 09:18:30 2011 : Info: # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default Mon Sep 26 09:18:30 2011 : Info: +- entering group authorize {...} Mon Sep 26 09:18:30 2011 : Info: ++[preprocess] returns ok Mon Sep 26 09:18:30 2011 : Info: ++[chap] returns noop Mon Sep 26 09:18:30 2011 : Info: ++[mschap] returns noop Mon Sep 26 09:18:30 2011 : Info: ++[digest] returns noop Mon Sep 26 09:18:30 2011 : Info: [ntdomain] Looking up realm "RC24558" for User-Name = "RC24558\jojo" Mon Sep 26 09:18:30 2011 : Info: [ntdomain] Found realm "~.*" Mon Sep 26 09:18:30 2011 : Info: [ntdomain] Adding Stripped-User-Name = "jojo" Mon Sep 26 09:18:30 2011 : Info: [ntdomain] Adding Realm = "RC24558" Mon Sep 26 09:18:30 2011 : Info: [ntdomain] Authentication realm is LOCAL. Mon Sep 26 09:18:30 2011 : Info: ++[ntdomain] returns ok Mon Sep 26 09:18:30 2011 : Info: [eap] EAP packet type response id 10 length 86 Mon Sep 26 09:18:30 2011 : Info: [eap] Continuing tunnel setup. Mon Sep 26 09:18:30 2011 : Info: ++[eap] returns ok Mon Sep 26 09:18:30 2011 : Info: Found Auth-Type = EAP Mon Sep 26 09:18:30 2011 : Info: # Executing group from file /usr/local/etc/raddb/sites-enabled/default Mon Sep 26 09:18:30 2011 : Info: +- entering group authenticate {...} Mon Sep 26 09:18:30 2011 : Info: [eap] Request found, released from the list Mon Sep 26 09:18:30 2011 : Info: [eap] EAP/peap Mon Sep 26 09:18:30 2011 : Info: [eap] processing type peap Mon Sep 26 09:18:30 2011 : Info: [peap] processing EAP-TLS Mon Sep 26 09:18:30 2011 : Info: [peap] eaptls_verify returned 7 Mon Sep 26 09:18:30 2011 : Info: [peap] Done initial handshake Mon Sep 26 09:18:30 2011 : Info: [peap] eaptls_process returned 7 Mon Sep 26 09:18:30 2011 : Info: [peap] EAPTLS_OK Mon Sep 26 09:18:30 2011 : Info: [peap] Session established. Decoding tunneled attributes. Mon Sep 26 09:18:30 2011 : Info: [peap] Peap state phase2 Mon Sep 26 09:18:30 2011 : Info: [peap] EAP type mschapv2 Mon Sep 26 09:18:30 2011 : Info: [peap] Got tunneled request EAP-Message = 0x020a003f1a020a003a31c6af5159a443456abed7a200f914b32000000000000000008e0db552067e6773741a27b5fa900f3995ed3e020ded66d9006a6f6a6f server { Mon Sep 26 09:18:30 2011 : Info: [peap] Setting User-Name to RC24558\jojo Sending tunneled request EAP-Message = 0x020a003f1a020a003a31c6af5159a443456abed7a200f914b32000000000000000008e0db552067e6773741a27b5fa900f3995ed3e020ded66d9006a6f6a6f FreeRADIUS-Proxied-To = 127.0.0.1 User-Name = "RC24558\\jojo" State = 0x2e162f4f2e1c35eccc0848a7af8693ad Framed-MTU = 1400 Called-Station-Id = "0013.5ffa.57f0" Calling-Station-Id = "0013.ceca.3fb6" Service-Type = Login-User NAS-Port-Type = Wireless-802.11 NAS-Port = 15159 NAS-IP-Address = 10.0.14.36 NAS-Identifier = "ap" server inner-tunnel { Mon Sep 26 09:18:30 2011 : Info: # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/inner-tunnel Mon Sep 26 09:18:30 2011 : Info: +- entering group authorize {...} Mon Sep 26 09:18:30 2011 : Info: ++[mschap] returns noop Mon Sep 26 09:18:30 2011 : Info: [ntdomain] Looking up realm "RC24558" for User-Name = "RC24558\jojo" Mon Sep 26 09:18:30 2011 : Info: [ntdomain] Found realm "~.*" Mon Sep 26 09:18:30 2011 : Info: [ntdomain] Adding Stripped-User-Name = "jojo" Mon Sep 26 09:18:30 2011 : Info: [ntdomain] Adding Realm = "RC24558" Mon Sep 26 09:18:30 2011 : Info: [ntdomain] Authentication realm is LOCAL. Mon Sep 26 09:18:30 2011 : Info: ++[ntdomain] returns ok Mon Sep 26 09:18:30 2011 : Info: ++[control] returns ok Mon Sep 26 09:18:30 2011 : Info: [eap] EAP packet type response id 10 length 63 Mon Sep 26 09:18:30 2011 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation Mon Sep 26 09:18:30 2011 : Info: ++[eap] returns updated Mon Sep 26 09:18:30 2011 : Info: ++[files] returns noop Mon Sep 26 09:18:30 2011 : Info: [ldap] performing user authorization for jojo Mon Sep 26 09:18:30 2011 : Info: [ldap] expand: %{Stripped-User-Name} -> jojo Mon Sep 26 09:18:30 2011 : Info: [ldap] expand: (uid=%{%{Stripped-User-Name}:-%{User-Name}}) -> (uid=jojo) Mon Sep 26 09:18:30 2011 : Info: [ldap] expand: ou=Users,dc=rcsd -> ou=Users,dc=rcsd Mon Sep 26 09:18:30 2011 : Debug: [ldap] ldap_get_conn: Checking Id: 0 Mon Sep 26 09:18:30 2011 : Debug: [ldap] ldap_get_conn: Got Id: 0 Mon Sep 26 09:18:30 2011 : Debug: [ldap] performing search in ou=Users,dc=rcsd, with filter (uid=jojo) Mon Sep 26 09:18:30 2011 : Info: [ldap] checking if remote access for jojo is allowed by uid Mon Sep 26 09:18:30 2011 : Info: [ldap] looking for check items in directory... Mon Sep 26 09:18:30 2011 : Debug: [ldap] userPassword -> Password-With-Header == "{SSHA}II8f7AGFYlC1KCv9i1ciQO5U9qNG1RrG" Mon Sep 26 09:18:30 2011 : Debug: [ldap] sambaNtPassword -> NT-Password == 0x3530354139323739434644324639344336353839383035353143464445373335 Mon Sep 26 09:18:30 2011 : Info: [ldap] looking for reply items in directory... Mon Sep 26 09:18:30 2011 : Info: [ldap] user jojo authorized to use remote access Mon Sep 26 09:18:30 2011 : Debug: [ldap] ldap_release_conn: Release Id: 0 Mon Sep 26 09:18:30 2011 : Info: ++[ldap] returns ok Mon Sep 26 09:18:30 2011 : Info: ++[expiration] returns noop Mon Sep 26 09:18:30 2011 : Info: ++[logintime] returns noop Mon Sep 26 09:18:30 2011 : Info: [pap] Normalizing NT-Password from hex encoding Mon Sep 26 09:18:30 2011 : Info: [pap] Normalizing SSHA1-Password from base64 encoding Mon Sep 26 09:18:30 2011 : Info: [pap] WARNING: Auth-Type already set. Not setting to PAP Mon Sep 26 09:18:30 2011 : Info: ++[pap] returns noop Mon Sep 26 09:18:30 2011 : Info: Found Auth-Type = EAP Mon Sep 26 09:18:30 2011 : Info: # Executing group from file /usr/local/etc/raddb/sites-enabled/inner-tunnel Mon Sep 26 09:18:30 2011 : Info: +- entering group authenticate {...} Mon Sep 26 09:18:30 2011 : Info: [eap] Request found, released from the list Mon Sep 26 09:18:30 2011 : Info: [eap] EAP/mschapv2 Mon Sep 26 09:18:30 2011 : Info: [eap] processing type mschapv2 Mon Sep 26 09:18:30 2011 : Info: [mschapv2] # Executing group from file /usr/local/etc/raddb/sites-enabled/inner-tunnel Mon Sep 26 09:18:30 2011 : Info: [mschapv2] +- entering group MS-CHAP {...} Mon Sep 26 09:18:30 2011 : Info: [mschap] No Cleartext-Password configured. Cannot create LM-Password. Mon Sep 26 09:18:30 2011 : Info: [mschap] Found NT-Password Mon Sep 26 09:18:30 2011 : Info: [mschap] ERROR: User-Name (RC24558\jojo) is not the same as MS-CHAP Name (jojo) from EAP-MSCHAPv2 Mon Sep 26 09:18:30 2011 : Info: ++[mschap] returns reject Mon Sep 26 09:18:30 2011 : Info: [eap] Freeing handler Mon Sep 26 09:18:30 2011 : Info: ++[eap] returns reject Mon Sep 26 09:18:30 2011 : Info: Failed to authenticate the user. } # server inner-tunnel Mon Sep 26 09:18:30 2011 : Info: [peap] Got tunneled reply code 3 EAP-Message = 0x040a0004 Message-Authenticator = 0x00000000000000000000000000000000 Mon Sep 26 09:18:30 2011 : Info: [peap] Got tunneled reply RADIUS code 3 EAP-Message = 0x040a0004 Message-Authenticator = 0x00000000000000000000000000000000 Mon Sep 26 09:18:30 2011 : Info: [peap] Tunneled authentication was rejected. Mon Sep 26 09:18:30 2011 : Info: [peap] FAILURE Mon Sep 26 09:18:30 2011 : Info: ++[eap] returns handled Sending Access-Challenge of id 150 to 10.0.14.36 port 1645 EAP-Message = 0x010b00261900170301001b944643d51444d64e2acfa39f31f4d500d4c9671ee00bb2532b3067 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x012a67f109217eb59928657b4c6fcae7 Mon Sep 26 09:18:30 2011 : Info: Finished request 8. Mon Sep 26 09:18:30 2011 : Debug: Going to the next request Mon Sep 26 09:18:30 2011 : Debug: Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 10.0.14.36 port 1645, id=151, length=176 User-Name = "RC24558\\jojo" Framed-MTU = 1400 Called-Station-Id = "0013.5ffa.57f0" Calling-Station-Id = "0013.ceca.3fb6" Service-Type = Login-User Message-Authenticator = 0x7d8d32826fedff54623bb8f7c4b76818 EAP-Message = 0x020b00261900170301001bb32976eb7fbb6643e7c9fc5dee1e4ddcacc7e437fbb7d1a58cfcc2 NAS-Port-Type = Wireless-802.11 NAS-Port = 15159 State = 0x012a67f109217eb59928657b4c6fcae7 NAS-IP-Address = 10.0.14.36 NAS-Identifier = "ap" Mon Sep 26 09:18:30 2011 : Info: # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default Mon Sep 26 09:18:30 2011 : Info: +- entering group authorize {...} Mon Sep 26 09:18:30 2011 : Info: ++[preprocess] returns ok Mon Sep 26 09:18:30 2011 : Info: ++[chap] returns noop Mon Sep 26 09:18:30 2011 : Info: ++[mschap] returns noop Mon Sep 26 09:18:30 2011 : Info: ++[digest] returns noop Mon Sep 26 09:18:30 2011 : Info: [ntdomain] Looking up realm "RC24558" for User-Name = "RC24558\jojo" Mon Sep 26 09:18:30 2011 : Info: [ntdomain] Found realm "~.*" Mon Sep 26 09:18:30 2011 : Info: [ntdomain] Adding Stripped-User-Name = "jojo" Mon Sep 26 09:18:30 2011 : Info: [ntdomain] Adding Realm = "RC24558" Mon Sep 26 09:18:30 2011 : Info: [ntdomain] Authentication realm is LOCAL. Mon Sep 26 09:18:30 2011 : Info: ++[ntdomain] returns ok Mon Sep 26 09:18:30 2011 : Info: [eap] EAP packet type response id 11 length 38 Mon Sep 26 09:18:30 2011 : Info: [eap] Continuing tunnel setup. Mon Sep 26 09:18:30 2011 : Info: ++[eap] returns ok Mon Sep 26 09:18:30 2011 : Info: Found Auth-Type = EAP Mon Sep 26 09:18:30 2011 : Info: # Executing group from file /usr/local/etc/raddb/sites-enabled/default Mon Sep 26 09:18:30 2011 : Info: +- entering group authenticate {...} Mon Sep 26 09:18:30 2011 : Info: [eap] Request found, released from the list Mon Sep 26 09:18:30 2011 : Info: [eap] EAP/peap Mon Sep 26 09:18:30 2011 : Info: [eap] processing type peap Mon Sep 26 09:18:30 2011 : Info: [peap] processing EAP-TLS Mon Sep 26 09:18:30 2011 : Info: [peap] eaptls_verify returned 7 Mon Sep 26 09:18:30 2011 : Info: [peap] Done initial handshake Mon Sep 26 09:18:30 2011 : Info: [peap] eaptls_process returned 7 Mon Sep 26 09:18:30 2011 : Info: [peap] EAPTLS_OK Mon Sep 26 09:18:30 2011 : Info: [peap] Session established. Decoding tunneled attributes. Mon Sep 26 09:18:30 2011 : Info: [peap] Peap state send tlv failure Mon Sep 26 09:18:30 2011 : Info: [peap] Received EAP-TLV response. Mon Sep 26 09:18:30 2011 : Info: [peap] The users session was previously rejected: returning reject (again.) Mon Sep 26 09:18:30 2011 : Info: [peap] *** This means you need to read the PREVIOUS messages in the debug output Mon Sep 26 09:18:30 2011 : Info: [peap] *** to find out the reason why the user was rejected. Mon Sep 26 09:18:30 2011 : Info: [peap] *** Look for "reject" or "fail". Those earlier messages will tell you. Mon Sep 26 09:18:30 2011 : Info: [peap] *** what went wrong, and how to fix the problem. Mon Sep 26 09:18:30 2011 : Info: [eap] Handler failed in EAP/peap Mon Sep 26 09:18:30 2011 : Info: [eap] Failed in EAP select Mon Sep 26 09:18:30 2011 : Info: ++[eap] returns invalid Mon Sep 26 09:18:30 2011 : Info: Failed to authenticate the user. Mon Sep 26 09:18:30 2011 : Info: Using Post-Auth-Type Reject Mon Sep 26 09:18:30 2011 : Info: # Executing group from file /usr/local/etc/raddb/sites-enabled/default Mon Sep 26 09:18:30 2011 : Info: +- entering group REJECT {...} Mon Sep 26 09:18:30 2011 : Info: [attr_filter.access_reject] expand: %{User-Name} -> RC24558\jojo Mon Sep 26 09:18:30 2011 : Debug: attr_filter: Matched entry DEFAULT at line 11 Mon Sep 26 09:18:30 2011 : Info: ++[attr_filter.access_reject] returns updated Mon Sep 26 09:18:30 2011 : Info: Delaying reject of request 9 for 1 seconds Mon Sep 26 09:18:30 2011 : Debug: Going to the next request Mon Sep 26 09:18:30 2011 : Debug: Waking up in 0.9 seconds. Mon Sep 26 09:18:31 2011 : Info: Sending delayed reject for request 9 Sending Access-Reject of id 151 to 10.0.14.36 port 1645 EAP-Message = 0x040b0004 Message-Authenticator = 0x00000000000000000000000000000000 Mon Sep 26 09:18:31 2011 : Debug: Waking up in 3.9 seconds. Mon Sep 26 09:18:34 2011 : Debug: Waking up in 1.3 seconds. Mon Sep 26 09:18:35 2011 : Info: Cleaning up request 0 ID 142 with timestamp +6 Mon Sep 26 09:18:35 2011 : Info: Cleaning up request 1 ID 143 with timestamp +6 Mon Sep 26 09:18:35 2011 : Info: Cleaning up request 2 ID 144 with timestamp +6 Mon Sep 26 09:18:35 2011 : Info: Cleaning up request 3 ID 145 with timestamp +6 Mon Sep 26 09:18:35 2011 : Info: Cleaning up request 4 ID 146 with timestamp +6 Mon Sep 26 09:18:35 2011 : Info: Cleaning up request 5 ID 147 with timestamp +6 Mon Sep 26 09:18:35 2011 : Info: Cleaning up request 6 ID 148 with timestamp +6 Mon Sep 26 09:18:35 2011 : Info: Cleaning up request 7 ID 149 with timestamp +6 Mon Sep 26 09:18:35 2011 : Info: Cleaning up request 8 ID 150 with timestamp +6 Mon Sep 26 09:18:35 2011 : Debug: Waking up in 1.0 seconds. Mon Sep 26 09:18:36 2011 : Info: Cleaning up request 9 ID 151 with timestamp +6 Mon Sep 26 09:18:36 2011 : Debug: Waking up in 0.1 seconds. Mon Sep 26 09:18:36 2011 : Info: Cleaning up request 10 ID 152 with timestamp +7 Mon Sep 26 09:18:37 2011 : Info: Cleaning up request 11 ID 153 with timestamp +8 Mon Sep 26 09:18:37 2011 : Info: Cleaning up request 12 ID 154 with timestamp +8 Mon Sep 26 09:18:37 2011 : Info: Cleaning up request 13 ID 155 with timestamp +8 Mon Sep 26 09:18:37 2011 : Info: Cleaning up request 14 ID 156 with timestamp +8 Mon Sep 26 09:18:37 2011 : Info: Cleaning up request 15 ID 157 with timestamp +8 Mon Sep 26 09:18:37 2011 : Info: Cleaning up request 16 ID 158 with timestamp +8 Mon Sep 26 09:18:37 2011 : Info: Cleaning up request 17 ID 159 with timestamp +8 Mon Sep 26 09:18:37 2011 : Info: Cleaning up request 18 ID 160 with timestamp +8 Mon Sep 26 09:18:37 2011 : Debug: Waking up in 1.0 seconds. Mon Sep 26 09:18:38 2011 : Info: Cleaning up request 19 ID 161 with timestamp +8 Mon Sep 26 09:18:38 2011 : Debug: Waking up in 0.1 seconds. Mon Sep 26 09:18:38 2011 : Info: Cleaning up request 20 ID 162 with timestamp +9 Mon Sep 26 09:18:38 2011 : Info: Cleaning up request 21 ID 163 with timestamp +9 Mon Sep 26 09:18:38 2011 : Info: Cleaning up request 22 ID 164 with timestamp +9 Mon Sep 26 09:18:38 2011 : Info: Cleaning up request 23 ID 165 with timestamp +9 Mon Sep 26 09:18:38 2011 : Info: Cleaning up request 24 ID 166 with timestamp +9 Mon Sep 26 09:18:38 2011 : Info: Cleaning up request 25 ID 167 with timestamp +9 Mon Sep 26 09:18:38 2011 : Info: Cleaning up request 26 ID 168 with timestamp +9 Mon Sep 26 09:18:38 2011 : Info: Cleaning up request 27 ID 169 with timestamp +9 Mon Sep 26 09:18:38 2011 : Info: Cleaning up request 28 ID 170 with timestamp +9 Mon Sep 26 09:18:38 2011 : Debug: Waking up in 1.0 seconds. Mon Sep 26 09:18:39 2011 : Info: Cleaning up request 29 ID 171 with timestamp +9 Mon Sep 26 09:18:39 2011 : Info: Ready to process requests. -- View this message in context: http://freeradius.1045715.n5.nabble.com/mschap-ERROR-User-Name-RC24558-jojo… Sent from the FreeRadius - User mailing list archive at Nabble.com.

1 0

Re: Re: rlm_sql not checking radgroupreply
by John Dunning 26 Sep '11

26 Sep '11

Arran, Yea - I did give that a try. I'm not sure if fall-through appears in the reply list at the end of the transaction like the other attributes do, but it didn't show up, nor did the group attributes show up. JD Re: rlm_sql not checking radgroupreply To: FreeRadius users mailing list <freeradius-users(a)lists.freeradius.org ( mailto:freeradius-users%40lists.freeradius.org )> Subject: Re: rlm_sql not checking radgroupreply From: Arran Cudbard-Bell <a.cudbardb(a)freeradius.org ( mailto:a.cudbardb%40freeradius.org )> Date: Mon, 26 Sep 2011 18:50:32 +0200 In-reply-to: < ( mailto:4E806228.97D9.0098.1%40wsc.edu )4E806228.97D9.0098.1(a)wsc.edu ( http://lists.freeradius.org/pipermail/freeradius-users/2011-September/msg00… )> References: < ( mailto:4E806228.97D9.0098.1%40wsc.edu )4E806228.97D9.0098.1(a)wsc.edu ( http://lists.freeradius.org/pipermail/freeradius-users/2011-September/msg00… )> Reply-to: FreeRadius users mailing list <freeradius-users(a)lists.freeradius.org ( mailto:freeradius-users%40lists.freeradius.org )> I have the read_groups setting set to "yes" in sql.conf and the debug log would make it appear that it's reading it in correctly. The mac is found in radcheck and any attributes in radreply are correctly returned, but rlm_sql never checks for any group memberships at all. I've done a trace on the sql server and it confirms what I see in the debug log from radius - it just never checks. Thoughts? Weird... Have you tried setting Fall-Through := yes in radcheck... In theory you shouldn't need to, but just to see if it works. -Arran Arran Cudbard-Bell a.cudbardb(a)freeradius.org Betelwiki, Betelwiki, Betelwiki.... http://wiki.freeradius.org/ ! References: rlm_sql not checking radgroupreply ( http://lists.freeradius.org/pipermail/freeradius-users/2011-September/msg00… ) From: "John Dunning" <jodunni1(a)wsc.edu> Previous by Date: Re: EAP authentication accept, user not found ( http://lists.freeradius.org/pipermail/freeradius-users/2011-September/msg00… ) Previous by Thread: rlm_sql not checking radgroupreply ( http://lists.freeradius.org/pipermail/freeradius-users/2011-September/msg00… ) Next by Thread: run more than one radius on single machine ( http://lists.freeradius.org/pipermail/freeradius-users/2011-September/msg00… ) Freeradius-Users September 2011 archives indexes sorted by: [ thread ] ( http://lists.freeradius.org/pipermail/freeradius-users/2011-September/threa… ) [ subject ] ( http://lists.freeradius.org/pipermail/freeradius-users/2011-September/subje… ) [ author ] ( http://lists.freeradius.org/pipermail/freeradius-users/2011-September/autho… ) [ date ] ( http://lists.freeradius.org/pipermail/freeradius-users/2011-September/date.… ) Freeradius-Users list archive Table of Contents ( http://lists.freeradius.org/pipermail/freeradius-users/index.html ) More information about the Freeradius-Users mailing list ( http://lists.freeradius.org/mailman/listinfo/freeradius-users ) This archive was generated by a fusion of Pipermail (Mailman edition) and MHonArc ( http://www.mhonarc.org/ ).

2 4