- Freeradius-Users - lists.freeradius.org

LDAP authorization without group attribute
by Walter Reynolds 13 May '14

13 May '14

I am running Freeradius 2.2.4 and am not quite sure where to go with this. I have read the documentation, but my need does not quite match. We have the standard EAP-PEAP setup where users are authenticated against AD via ntlm-auth. What I need to do is add an authorization check to determine if a users should get a specific VLAN attribute sent back or be placed in a default VLAN (This is so we can only allow access to library resources to those that should be allowed). Now, if I had a LDAP group that contained these I could use a simple group setup listed in the http://wiki.freeradius.org/modules/Rlm_ldap page. My problem is, the attribute that contains the data about the affiliation is a multi valued attribute UMICHINSTROLES StudentAA, StudentDBRN, and StudentFLNT (continuing and incoming students regardless of enrollment; includes detached study); EnrolledStudentAA, EnrolledStudentDBRN, EnrolledStudentFLNT (enrolled in at least one credit hour for ""current"" term; next term information is used during gap between terms) AlumniAA, AlumniDBRN, AlumniFLNT (any person who has completed at least one semester in a degree-granting program) FacultyAA, FacultyDBRN, FacultyFLNT (defined as academic, instructional, and research appointments; includes emeritus faculty) RegularStaffAA, RegularStaffDBRN, RegularStaffFLNT (current appointment with a status of active, suspended, short-work break, leave, or paid leave); TemporaryStaffAA, TemporaryStaffDBRN, TemporaryStaffFLNT (current appointment with a status of active, suspended, short-work break, leave, or paid leave) Retiree (retired from any U-Mcampus, regardless of other appoints that may still be active) SponsoredAffiliateAA, SponsoredAffiliateDBRN, SponsoredAffiliateFLNT (has at least one departmental sponsorship). Is there a way to make the group match a specific set of these values? (I can do that with the Cisco VPN DAP policies) Something along these lines (again based on group section from wiki)l post-auth { if (LDAP-Group == "umichinstroles=*FacultyAA") { Assign VLAN Special } elsif (LDAP-Group == "umichinstroles=*StudentAA") { Assign VLAN Special } else { Assign VLAN Default } } Another path of thought was to specify a filter in the LDAP module config to something like this. filter = "(&(uid=%{Stripped-User-Name:-%{User-Name}})(|(umichinstroles=*AffiliateAA)(umichinstroles=*FacultyAA)(umichinstroles=*StudentAA)(umichinstroles=*StaffAA)))" So that works as far as only responding if a user matches one of those, but then how would I apply a VLAN for them and leave everyone else in a default VLAN? There must be a way to do this but my lack of LDAP knowledge is not helping me see how to do this and the guides I find do not seem help. Any help would be appreciated. ------------------------ Walter Reynolds Principal Systems Security Development Engineer Information and Technology Services University of Michigan (734) 615-9438

2 1

seg fault FR 3.0.2
by Łukasz Serwatka 13 May '14

13 May '14

Hi, i need help with FR 3.0.2 i use only dhcp i on my production server i have seg fault in message log kernel: radiusd[10692] general protection ip:7fa642360ba1 sp:7fff2057e760 error:0 in libfreeradius-radius.so[7fa642342000+2f000] when i use ps i see memory leak every few sec VSZ is inc +4 VSZ 11442 0.0 0.1 432332 7404 ? Ssl 08:14 0:00 /usr/local/sbin/radiusd could you give me some tips how to bug this issue ?? on my lab server i didn't saw this issue but i don't have soo many dhcp packet there on production i have 30 request per sec to dhcp if u need a dump radiusd -X just let me know Centos 6.4 64bit sry 4 my english regards Luc

2 3

radclient / perl, slightly OT
by Chris Knipe 13 May '14

13 May '14

Hi All, I execute radclient from a perl application to send POD requests: open(RADIUSCLIENT, "| /usr/bin/radclient -c 1 -r 1 " . $RAD_REQUEST{'NAS-IP-Address'} . ":3799 disconnect secret"); print RADIUSCLIENT "User-Name=" . $RAD_REQUEST{'User-Name'} . "\n"; print RADIUSCLIENT "NAS-IP-Address=" . $RAD_REQUEST{'NAS-IP-Address'} . "\n"; print RADIUSCLIENT "Framed-IP-Address=" . $RAD_REQUEST{'Framed-IP-Address'} . "\n"; print RADIUSCLIENT "Acct-Session-Id=" . $RAD_REQUEST{'Acct-Session-Id'} . "\n"; close(RADIUSCLIENT); The above works fine, but I have no idea on how to determine whether the request was sent successfully, or even better, accepted by the NAS. Can someone that perhaps does something similar with radclient & perl perhaps just give me a quick hack on how to call radclient so that it reads the attributes from STDIN, whilst it still allows me to parse all the output in perl? Ideally for future expansion in terms of functionality, I would want to read the full output from radclient (incl. all attributes returned) back into my perl application. I do apologize for the for the OT post. -- Chris.

4 4

simultaneous login(s) is not working
by Russell Mike 13 May '14

13 May '14

Dear List simultaneous login(s) is not working here. Does it include any other steps than listed here. *STEP: 1* Query From dialup.conf: simul_count_query = "SELECT COUNT(*) \ FROM ${acct_table1} \ WHERE username = '%{SQL-User-Name}' \ AND acctstoptime IS NULL" simul_verify_query = "SELECT radacctid, acctsessionid, username, \ nasipaddress, nasportid, framedipaddress, \ callingstationid, framedprotocol \ FROM ${acct_table1} \ WHERE username = '%{SQL-User-Name}' \ AND acctstoptime IS NULL" *STEP: 2*session { sql } *STEP: 3 - *in the database Simultaneous-Use := 1 Thanks / --RM

5 15

Re: EAP-TTLS session resumption does not work.
by hashimotoku＠nttdata.co.jp 13 May '14

13 May '14

Thanks for your reply. > what client? We are using Windows 7 OS, and Odyssey Access Client as WiFi supplicant. > has the fast session resumption been enabled on on it? Yes. When we used another RADIUS server, session resumption worked well. > - FreeRadius version. > 3.0.1 old (very!) and some bugs. please upgrade. Sure. I have upgraded FreeRadius, but still the same issue occurs. - This is Debug output. (radius -X) Tue May 13 08:18:55 2014 : Info: radiusd: FreeRADIUS Version 3.0.2, for host i686-pc-linux-gnu, built on May 13 2014 at 08:05:52 Tue May 13 08:18:55 2014 : Debug: Server was built with: Tue May 13 08:18:55 2014 : Debug: accounting Tue May 13 08:18:55 2014 : Debug: authentication Tue May 13 08:18:55 2014 : Debug: ascend binary attributes Tue May 13 08:18:55 2014 : Debug: coa Tue May 13 08:18:55 2014 : Debug: control-socket Tue May 13 08:18:55 2014 : Debug: detail Tue May 13 08:18:55 2014 : Debug: dhcp Tue May 13 08:18:55 2014 : Debug: dynamic clients Tue May 13 08:18:55 2014 : Debug: proxy Tue May 13 08:18:55 2014 : Debug: regex-posix Tue May 13 08:18:55 2014 : Debug: session-management Tue May 13 08:18:55 2014 : Debug: stats Tue May 13 08:18:55 2014 : Debug: tcp Tue May 13 08:18:55 2014 : Debug: threads Tue May 13 08:18:55 2014 : Debug: tls Tue May 13 08:18:55 2014 : Debug: unlang Tue May 13 08:18:55 2014 : Debug: vmps Tue May 13 08:18:55 2014 : Debug: Server core libs: Tue May 13 08:18:55 2014 : Debug: talloc : 2.0.* Tue May 13 08:18:55 2014 : Debug: ssl : OpenSSL 1.0.1g 7 Apr 2014 Tue May 13 08:18:55 2014 : Debug: Library magic number: Tue May 13 08:18:55 2014 : Debug: 0xf403000200000000 Tue May 13 08:18:55 2014 : Debug: Endianess: Tue May 13 08:18:55 2014 : Debug: little [1mTue May 13 08:18:55 2014 : Info: Copyright (C) 1999-2014 The FreeRADIUS server project and contributors[0m [1mTue May 13 08:18:55 2014 : Info: There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A[0m [1mTue May 13 08:18:55 2014 : Info: PARTICULAR PURPOSE[0m [1mTue May 13 08:18:55 2014 : Info: You may redistribute copies of FreeRADIUS under the terms of the[0m [1mTue May 13 08:18:55 2014 : Info: GNU General Public License[0m [1mTue May 13 08:18:55 2014 : Info: For more information about these matters, see the file named COPYRIGHT[0m [1mTue May 13 08:18:55 2014 : Info: Starting - reading configuration files ...[0m Tue May 13 08:18:55 2014 : Debug: including dictionary file /usr/local/freeradius-3.0.2/share/freeradius/dictionary Tue May 13 08:18:55 2014 : Debug: including dictionary file /usr/local/freeradius-3.0.2/etc/raddb/dictionary Tue May 13 08:18:55 2014 : Debug: including configuration file /usr/local/freeradius-3.0.2/etc/raddb/radiusd.conf Tue May 13 08:18:55 2014 : Debug: main { Tue May 13 08:18:55 2014 : Debug: security { Tue May 13 08:18:55 2014 : Debug: allow_core_dumps = no Tue May 13 08:18:55 2014 : Debug: } Tue May 13 08:18:55 2014 : Debug: } Tue May 13 08:18:55 2014 : Debug: main { Tue May 13 08:18:55 2014 : Debug: name = "freeradius" Tue May 13 08:18:55 2014 : Debug: prefix = "/usr/local" Tue May 13 08:18:55 2014 : Debug: localstatedir = "/usr/local/var" Tue May 13 08:18:55 2014 : Debug: sbindir = "/usr/local/sbin" Tue May 13 08:18:55 2014 : Debug: logdir = "/usr/local/var/log" Tue May 13 08:18:55 2014 : Debug: run_dir = "/usr/local/var/run/freeradius" Tue May 13 08:18:55 2014 : Debug: libdir = "/usr/local/lib" Tue May 13 08:18:55 2014 : Debug: radacctdir = "/usr/local/var/log/radacct" Tue May 13 08:18:55 2014 : Debug: hostname_lookups = no Tue May 13 08:18:55 2014 : Debug: max_request_time = 30 Tue May 13 08:18:55 2014 : Debug: cleanup_delay = 5 Tue May 13 08:18:55 2014 : Debug: max_requests = 256 Tue May 13 08:18:55 2014 : Debug: pidfile = "/var/run/radius/freeradius.pid" Tue May 13 08:18:55 2014 : Debug: checkrad = "/usr/local/sbin/checkrad" Tue May 13 08:18:55 2014 : Debug: debug_level = 0 Tue May 13 08:18:55 2014 : Debug: proxy_requests = yes Tue May 13 08:18:55 2014 : Debug: log { Tue May 13 08:18:55 2014 : Debug: stripped_names = no Tue May 13 08:18:55 2014 : Debug: auth = no Tue May 13 08:18:55 2014 : Debug: auth_badpass = no Tue May 13 08:18:55 2014 : Debug: auth_goodpass = no Tue May 13 08:18:55 2014 : Debug: msg_denied = "You are already logged in - access denied" Tue May 13 08:18:55 2014 : Debug: } Tue May 13 08:18:55 2014 : Debug: security { Tue May 13 08:18:55 2014 : Debug: max_attributes = 0 Tue May 13 08:18:55 2014 : Debug: reject_delay = 0 Tue May 13 08:18:55 2014 : Debug: status_server = no Tue May 13 08:18:55 2014 : Debug: } Tue May 13 08:18:55 2014 : Debug: } Tue May 13 08:18:55 2014 : Debug: radiusd: #### Loading Realms and Home Servers #### Tue May 13 08:18:55 2014 : Debug: realm tinyradius { Tue May 13 08:18:55 2014 : Debug: authhost = 127.0.0.1:18160 Tue May 13 08:18:55 2014 : Debug: secret = RadiusStubSecret Tue May 13 08:18:55 2014 : Debug: } Tue May 13 08:18:55 2014 : Debug: radiusd: #### Loading Clients #### Tue May 13 08:18:55 2014 : Debug: client 10.0.0.0/8 { Tue May 13 08:18:55 2014 : Debug: require_message_authenticator = no Tue May 13 08:18:55 2014 : Debug: secret = "xxxx" Tue May 13 08:18:55 2014 : Debug: limit { Tue May 13 08:18:55 2014 : Debug: max_connections = 16 Tue May 13 08:18:55 2014 : Debug: lifetime = 0 Tue May 13 08:18:55 2014 : Debug: idle_timeout = 30 Tue May 13 08:18:55 2014 : Debug: } Tue May 13 08:18:55 2014 : Debug: } Tue May 13 08:18:55 2014 : No 'ipaddr' or 'ipv6addr' field found in client 10.0.0.0/8. Please fix your configuration Tue May 13 08:18:55 2014 : Support for old-style clients will be removed in a future release Tue May 13 08:18:55 2014 : Debug: radiusd: #### Instantiating modules #### Tue May 13 08:18:55 2014 : Debug: Library not found at path "/usr/local/lib/rlm_eap.so" Tue May 13 08:18:55 2014 : Debug: (Loaded rlm_eap, checking if it's valid) Tue May 13 08:18:55 2014 : Debug: # Loaded module rlm_eap Tue May 13 08:18:55 2014 : Debug: # Instantiating module "eap" from file /usr/local/freeradius-3.0.2/etc/raddb/radiusd.conf Tue May 13 08:18:55 2014 : Debug: eap { Tue May 13 08:18:55 2014 : Debug: default_eap_type = "ttls" Tue May 13 08:18:55 2014 : Debug: timer_expire = 60 Tue May 13 08:18:55 2014 : Debug: ignore_unknown_eap_types = no Tue May 13 08:18:55 2014 : Debug: mod_accounting_username_bug = no Tue May 13 08:18:55 2014 : Debug: max_sessions = 2048 Tue May 13 08:18:55 2014 : Debug: } Tue May 13 08:18:55 2014 : Debug: Library not found at path "/usr/local/lib/rlm_eap_ttls.so" Tue May 13 08:18:55 2014 : Debug: # Linked to sub-module rlm_eap_ttls Tue May 13 08:18:55 2014 : Debug: ttls { Tue May 13 08:18:55 2014 : Debug: tls = "tls-common" Tue May 13 08:18:55 2014 : Debug: default_eap_type = "md5" Tue May 13 08:18:55 2014 : Debug: copy_request_to_tunnel = no Tue May 13 08:18:55 2014 : Debug: use_tunneled_reply = no Tue May 13 08:18:55 2014 : Debug: virtual_server = "inner-tunnel" Tue May 13 08:18:55 2014 : Debug: include_length = yes Tue May 13 08:18:55 2014 : Debug: require_client_cert = no Tue May 13 08:18:55 2014 : Debug: } Tue May 13 08:18:55 2014 : Debug: tls-config tls-common { Tue May 13 08:18:55 2014 : Debug: rsa_key_exchange = no Tue May 13 08:18:55 2014 : Debug: dh_key_exchange = yes Tue May 13 08:18:55 2014 : Debug: rsa_key_length = 512 Tue May 13 08:18:55 2014 : Debug: dh_key_length = 512 Tue May 13 08:18:55 2014 : Debug: verify_depth = 0 Tue May 13 08:18:55 2014 : Debug: pem_file_type = yes Tue May 13 08:18:55 2014 : Debug: private_key_file = "/usr/local/freeradius-3.0.2/etc/raddb/certs/top-otprad51v.key" Tue May 13 08:18:55 2014 : Debug: certificate_file = "/usr/local/freeradius-3.0.2/etc/raddb/certs/top-otprad51v.crt" Tue May 13 08:18:55 2014 : Debug: dh_file = "/usr/local/freeradius-3.0.2/etc/raddb/certs/dh" Tue May 13 08:18:55 2014 : Debug: fragment_size = 1024 Tue May 13 08:18:55 2014 : Debug: include_length = yes Tue May 13 08:18:55 2014 : Debug: check_crl = no Tue May 13 08:18:55 2014 : Debug: ecdh_curve = "prime256v1" Tue May 13 08:18:55 2014 : Debug: cache { Tue May 13 08:18:55 2014 : Debug: enable = no Tue May 13 08:18:55 2014 : Debug: lifetime = 24 Tue May 13 08:18:55 2014 : Debug: max_entries = 255 Tue May 13 08:18:55 2014 : Debug: } Tue May 13 08:18:55 2014 : Debug: verify { Tue May 13 08:18:55 2014 : Debug: } Tue May 13 08:18:55 2014 : Debug: ocsp { Tue May 13 08:18:55 2014 : Debug: enable = no Tue May 13 08:18:55 2014 : Debug: override_cert_url = no Tue May 13 08:18:55 2014 : Debug: use_nonce = yes Tue May 13 08:18:55 2014 : Debug: timeout = 0 Tue May 13 08:18:55 2014 : Debug: softfail = yes Tue May 13 08:18:55 2014 : Debug: } Tue May 13 08:18:55 2014 : Debug: } Tue May 13 08:18:55 2014 : Debug: radiusd: #### Loading Virtual Servers #### Tue May 13 08:18:55 2014 : Debug: server { # from file /usr/local/freeradius-3.0.2/etc/raddb/radiusd.conf Tue May 13 08:18:55 2014 : Debug: # Loading authenticate {...} Tue May 13 08:18:55 2014 : Debug: # Loading authorize {...} Tue May 13 08:18:55 2014 : Debug: # Loading post-proxy {...} Tue May 13 08:18:55 2014 : Debug: } # server Tue May 13 08:18:55 2014 : Debug: server inner-tunnel { # from file /usr/local/freeradius-3.0.2/etc/raddb/radiusd.conf Tue May 13 08:18:55 2014 : Debug: # Loading authenticate {...} Tue May 13 08:18:55 2014 : Debug: # Loading authorize {...} Tue May 13 08:18:55 2014 : Debug: } # server inner-tunnel Tue May 13 08:18:55 2014 : Debug: radiusd: #### Opening IP addresses and Ports #### Tue May 13 08:18:55 2014 : Debug: Library not found at path "/usr/local/lib/proto_auth.so" Tue May 13 08:18:55 2014 : Debug: listen { Tue May 13 08:18:55 2014 : Debug: type = "auth" Tue May 13 08:18:55 2014 : Debug: ipaddr = 10.33.22.38 Tue May 13 08:18:55 2014 : Debug: port = 18120 Tue May 13 08:18:55 2014 : Debug: } Tue May 13 08:18:55 2014 : Debug: Listening on auth address 10.33.22.38 port 18120 Tue May 13 08:18:55 2014 : Debug: Opening new proxy socket 'proxy address * port 0' Tue May 13 08:18:55 2014 : Debug: Listening on proxy address * port 59886 Tue May 13 08:18:55 2014 : Info: Ready to process requests. rad_recv: Access-Request packet from host 10.7.255.75 port 32806, id=127, length=183 User-Name = 'anonymous' NAS-IP-Address = 10.78.255.11 NAS-Port = 0 NAS-Identifier = '10.7.255.75' NAS-Port-Type = Wireless-802.11 Calling-Station-Id = '002100DB0DC5' Called-Station-Id = '000B866E4C48' Service-Type = Login-User Framed-MTU = 1100 EAP-Message = 0x0201000e01616e6f6e796d6f7573 Aruba-Essid-Name = 'otptest' Aruba-Location-Id = '1.14.25' Aruba-AP-Group = 'tys-low01' Message-Authenticator = 0x77b49a94be0b834482bc4f3f6b2a6318 Tue May 13 08:19:06 2014 : Debug: (0) # Executing section authorize from file /usr/local/freeradius-3.0.2/etc/raddb/radiusd.conf Tue May 13 08:19:06 2014 : Debug: (0) authorize { Tue May 13 08:19:06 2014 : Debug: (0) modsingle[authorize]: calling eap (rlm_eap) for request 0 Tue May 13 08:19:06 2014 : Debug: (0) eap : EAP packet type response id 1 length 14 Tue May 13 08:19:06 2014 : Debug: (0) eap : EAP-Identity reply, returning 'ok' so we can short-circuit the rest of authorize Tue May 13 08:19:06 2014 : Debug: (0) modsingle[authorize]: returned from eap (rlm_eap) for request 0 Tue May 13 08:19:06 2014 : Debug: (0) [eap] = ok Tue May 13 08:19:06 2014 : Debug: (0) } # authorize = ok Tue May 13 08:19:06 2014 : Debug: (0) Found Auth-Type = EAP Tue May 13 08:19:06 2014 : Debug: (0) # Executing group from file /usr/local/freeradius-3.0.2/etc/raddb/radiusd.conf Tue May 13 08:19:06 2014 : Debug: (0) authenticate { Tue May 13 08:19:06 2014 : Debug: (0) modsingle[authenticate]: calling eap (rlm_eap) for request 0 Tue May 13 08:19:06 2014 : Debug: (0) eap : Peer sent Identity (1) Tue May 13 08:19:06 2014 : Debug: (0) eap : Calling eap_ttls to process EAP data Tue May 13 08:19:06 2014 : Debug: (0) eap_ttls : Initiate Tue May 13 08:19:06 2014 : Debug: (0) eap_ttls : Start returned 1 Tue May 13 08:19:06 2014 : Debug: (0) eap : New EAP session, adding 'State' attribute to reply 0x2cd644782cd4515e Tue May 13 08:19:06 2014 : Debug: (0) modsingle[authenticate]: returned from eap (rlm_eap) for request 0 Tue May 13 08:19:06 2014 : Debug: (0) [eap] = handled Tue May 13 08:19:06 2014 : Debug: (0) } # authenticate = handled Sending Access-Challenge of id 127 from 10.33.22.38 port 18120 to 10.7.255.75 port 32806 EAP-Message = 0x010200061520 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x2cd644782cd4515e847c9f571e31e758 Tue May 13 08:19:06 2014 : Debug: (0) Finished request 0. Tue May 13 08:19:06 2014 : Debug: Waking up in 0.3 seconds. rad_recv: Access-Request packet from host 10.7.255.75 port 32806, id=128, length=287 User-Name = 'anonymous' NAS-IP-Address = 10.78.255.11 NAS-Port = 0 NAS-Identifier = '10.7.255.75' NAS-Port-Type = Wireless-802.11 Calling-Station-Id = '002100DB0DC5' Called-Station-Id = '000B866E4C48' Service-Type = Login-User Framed-MTU = 1100 EAP-Message = 0x0202006415800000005a16030100550100005103015371594c6441cee10cb8a9591fb6ba96826659757079944c40739c8dde4eadee00002a00160013006600150012000a0005000400070009006300650060006200610064001400110003000600080100 State = 0x2cd644782cd4515e847c9f571e31e758 Aruba-Essid-Name = 'otptest' Aruba-Location-Id = '1.14.25' Aruba-AP-Group = 'tys-low01' Message-Authenticator = 0x23e52ac2f5dae92ebc9f7a29283cc634 Tue May 13 08:19:06 2014 : Debug: (1) # Executing section authorize from file /usr/local/freeradius-3.0.2/etc/raddb/radiusd.conf Tue May 13 08:19:06 2014 : Debug: (1) authorize { Tue May 13 08:19:06 2014 : Debug: (1) modsingle[authorize]: calling eap (rlm_eap) for request 1 Tue May 13 08:19:06 2014 : Debug: (1) eap : EAP packet type response id 2 length 100 Tue May 13 08:19:06 2014 : Debug: (1) eap : Continuing tunnel setup. Tue May 13 08:19:06 2014 : Debug: (1) modsingle[authorize]: returned from eap (rlm_eap) for request 1 Tue May 13 08:19:06 2014 : Debug: (1) [eap] = ok Tue May 13 08:19:06 2014 : Debug: (1) } # authorize = ok Tue May 13 08:19:06 2014 : Debug: (1) Found Auth-Type = EAP Tue May 13 08:19:06 2014 : Debug: (1) # Executing group from file /usr/local/freeradius-3.0.2/etc/raddb/radiusd.conf Tue May 13 08:19:06 2014 : Debug: (1) authenticate { Tue May 13 08:19:06 2014 : Debug: (1) modsingle[authenticate]: calling eap (rlm_eap) for request 1 Tue May 13 08:19:06 2014 : Debug: (1) eap : Expiring EAP session with state 0x2cd644782cd4515e Tue May 13 08:19:06 2014 : Debug: (1) eap : Finished EAP session with state 0x2cd644782cd4515e Tue May 13 08:19:06 2014 : Debug: (1) eap : Previous EAP request found for state 0x2cd644782cd4515e, released from the list Tue May 13 08:19:06 2014 : Debug: (1) eap : Peer sent TTLS (21) Tue May 13 08:19:06 2014 : Debug: (1) eap : EAP TTLS (21) Tue May 13 08:19:06 2014 : Debug: (1) eap : Calling eap_ttls to process EAP data Tue May 13 08:19:06 2014 : Debug: (1) eap_ttls : Authenticate Tue May 13 08:19:06 2014 : Debug: (1) eap_ttls : processing EAP-TLS Tue May 13 08:19:06 2014 : Debug: TLS Length 90 Tue May 13 08:19:06 2014 : Debug: (1) eap_ttls : Length Included Tue May 13 08:19:06 2014 : Debug: (1) eap_ttls : eaptls_verify returned 11 Tue May 13 08:19:06 2014 : Debug: (1) eap_ttls : (other): before/accept initialization Tue May 13 08:19:06 2014 : Debug: (1) eap_ttls : TLS_accept: before/accept initialization Tue May 13 08:19:06 2014 : Debug: (1) eap_ttls : <<< TLS 1.0 Handshake [length 0055], ClientHello Tue May 13 08:19:06 2014 : Debug: (1) eap_ttls : TLS_accept: SSLv3 read client hello A Tue May 13 08:19:06 2014 : Debug: (1) eap_ttls : >>> TLS 1.0 Handshake [length 002a], ServerHello Tue May 13 08:19:06 2014 : Debug: (1) eap_ttls : TLS_accept: SSLv3 write server hello A Tue May 13 08:19:06 2014 : Debug: (1) eap_ttls : >>> TLS 1.0 Handshake [length 03cc], Certificate Tue May 13 08:19:06 2014 : Debug: (1) eap_ttls : TLS_accept: SSLv3 write certificate A Tue May 13 08:19:06 2014 : Debug: (1) eap_ttls : >>> TLS 1.0 Handshake [length 020d], ServerKeyExchange Tue May 13 08:19:06 2014 : Debug: (1) eap_ttls : TLS_accept: SSLv3 write key exchange A Tue May 13 08:19:06 2014 : Debug: (1) eap_ttls : >>> TLS 1.0 Handshake [length 0004], ServerHelloDone Tue May 13 08:19:06 2014 : Debug: (1) eap_ttls : TLS_accept: SSLv3 write server done A Tue May 13 08:19:06 2014 : Debug: (1) eap_ttls : TLS_accept: SSLv3 flush data Tue May 13 08:19:06 2014 : Debug: (1) eap_ttls : TLS_accept: Need to read more data: SSLv3 read client certificate A Tue May 13 08:19:06 2014 : Debug: In SSL Handshake Phase Tue May 13 08:19:06 2014 : Debug: In SSL Accept mode Tue May 13 08:19:06 2014 : Debug: (1) eap_ttls : eaptls_process returned 13 Tue May 13 08:19:06 2014 : Debug: (1) eap : New EAP session, adding 'State' attribute to reply 0x2cd644782dd5515e Tue May 13 08:19:06 2014 : Debug: (1) modsingle[authenticate]: returned from eap (rlm_eap) for request 1 Tue May 13 08:19:06 2014 : Debug: (1) [eap] = handled Tue May 13 08:19:06 2014 : Debug: (1) } # authenticate = handled Sending Access-Challenge of id 128 from 10.33.22.38 port 18120 to 10.7.255.75 port 32806 EAP-Message = 0x0103040015c00000061b160301002a020000260301aa3dfd948faf57718d7192f4e959c459bd08c6ed1334c18b9a64b2262e5652410000160016030103cc0b0003c80003c50003c2308203be308202a6020900d8e196b535b385dc300d06092a864886f70d01010505003081a0310b3009060355040613024a50310e300c06035504080c05546f6b796f310e300c06035504070c054368756f753110300e060355040a0c074e545444415441310c300a060355040b0c0349544d3128302606035504030c1f746f702d6f74707261643531762e6d6e672e6e7474646174612e636f2e6a703127302506092a864886f70d0109011618706f73746d6173746572406e7474646174612e636f2e6a70301e170d3134303431393131343534365a170d3135303431393131343534365a3081a0310b3009060355040613024a50310e300c06035504080c05546f6b796f310e300c06035504070c054368756f753110300e060355040a0c074e545444415441310c300a060355040b0c0349544d3128302606035504030c1f746f702d6f74707261643531762e6d6e672e6e7474646174612e636f2e6a703127302506092a864886f70d0109011618706f73746d6173746572406e7474646174612e636f2e6a7030820122300d06092a864886f70d01010105000382010f003082010a0282010100cbd1213f741 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x2cd644782dd5515e847c9f571e31e758 Tue May 13 08:19:06 2014 : Debug: (1) Finished request 1. Tue May 13 08:19:06 2014 : Debug: Waking up in 0.2 seconds. rad_recv: Access-Request packet from host 10.7.255.75 port 32806, id=129, length=193 User-Name = 'anonymous' NAS-IP-Address = 10.78.255.11 NAS-Port = 0 NAS-Identifier = '10.7.255.75' NAS-Port-Type = Wireless-802.11 Calling-Station-Id = '002100DB0DC5' Called-Station-Id = '000B866E4C48' Service-Type = Login-User Framed-MTU = 1100 EAP-Message = 0x020300061500 State = 0x2cd644782dd5515e847c9f571e31e758 Aruba-Essid-Name = 'otptest' Aruba-Location-Id = '1.14.25' Aruba-AP-Group = 'tys-low01' Message-Authenticator = 0xf0c302d7d3a5ad8337a272b4c6e639d1 Tue May 13 08:19:06 2014 : Debug: (2) # Executing section authorize from file /usr/local/freeradius-3.0.2/etc/raddb/radiusd.conf Tue May 13 08:19:06 2014 : Debug: (2) authorize { Tue May 13 08:19:06 2014 : Debug: (2) modsingle[authorize]: calling eap (rlm_eap) for request 2 Tue May 13 08:19:06 2014 : Debug: (2) eap : EAP packet type response id 3 length 6 Tue May 13 08:19:06 2014 : Debug: (2) eap : Continuing tunnel setup. Tue May 13 08:19:06 2014 : Debug: (2) modsingle[authorize]: returned from eap (rlm_eap) for request 2 Tue May 13 08:19:06 2014 : Debug: (2) [eap] = ok Tue May 13 08:19:06 2014 : Debug: (2) } # authorize = ok Tue May 13 08:19:06 2014 : Debug: (2) Found Auth-Type = EAP Tue May 13 08:19:06 2014 : Debug: (2) # Executing group from file /usr/local/freeradius-3.0.2/etc/raddb/radiusd.conf Tue May 13 08:19:06 2014 : Debug: (2) authenticate { Tue May 13 08:19:06 2014 : Debug: (2) modsingle[authenticate]: calling eap (rlm_eap) for request 2 Tue May 13 08:19:06 2014 : Debug: (2) eap : Expiring EAP session with state 0x2cd644782dd5515e Tue May 13 08:19:06 2014 : Debug: (2) eap : Finished EAP session with state 0x2cd644782dd5515e Tue May 13 08:19:06 2014 : Debug: (2) eap : Previous EAP request found for state 0x2cd644782dd5515e, released from the list Tue May 13 08:19:06 2014 : Debug: (2) eap : Peer sent TTLS (21) Tue May 13 08:19:06 2014 : Debug: (2) eap : EAP TTLS (21) Tue May 13 08:19:06 2014 : Debug: (2) eap : Calling eap_ttls to process EAP data Tue May 13 08:19:06 2014 : Debug: (2) eap_ttls : Authenticate Tue May 13 08:19:06 2014 : Debug: (2) eap_ttls : processing EAP-TLS Tue May 13 08:19:06 2014 : Debug: (2) eap_ttls : Received TLS ACK Tue May 13 08:19:06 2014 : Debug: (2) eap_ttls : Received TLS ACK Tue May 13 08:19:06 2014 : Debug: (2) eap_ttls : ACK handshake fragment handler Tue May 13 08:19:06 2014 : Debug: (2) eap_ttls : eaptls_verify returned 1 Tue May 13 08:19:06 2014 : Debug: (2) eap_ttls : eaptls_process returned 13 Tue May 13 08:19:06 2014 : Debug: (2) eap : New EAP session, adding 'State' attribute to reply 0x2cd644782ed2515e Tue May 13 08:19:06 2014 : Debug: (2) modsingle[authenticate]: returned from eap (rlm_eap) for request 2 Tue May 13 08:19:06 2014 : Debug: (2) [eap] = handled Tue May 13 08:19:06 2014 : Debug: (2) } # authenticate = handled Sending Access-Challenge of id 129 from 10.33.22.38 port 18120 to 10.7.255.75 port 32806 EAP-Message = 0x0104022f15800000061b1656ba74fcd8aabc61ca160301020d0c0002090080f9ff408fde4339b038b6d70ffa17ddc5efd2b8a760df3f5f914e5547417d84139c0bdf7692016aba5f138e0f574a062f54f8c3c93a13a9268320eb5ea1cdb6295a102a424aa2bc0a7c058c1ec7466c81acaa48424f451b2ff0a85c87cff71735a1b337edcc5c911b4290f67be096967d7361bd217b976f2c692ef4ce1a7d26630001020080792424f5fbdb401a5956c8f425f9ae995964791cb8815a595ef9cc19ab72dfe326f814b2c9f8022f8ce13f2cdeb0909a838323ded83402f782c317acfac87dc9aa657b485820656d44a48387944c2143bab572e6719834cee607fa76f664884db3b166f1adb732c2f802bc281665352847b3f5ce2069c20c8e7bb704128bdbfc01004a596ce2100aa79acdce35e407c67eb23b03829b46ba6f250c22cec2a780e3ea9b89cfeb2420bbb1f00bcdd047761bbf0e9cf25003854dc940ffc57958ddb7790f40a0c923e5e99f8661485223fdd6e27689142d2fc0a8cf75a8593fab2bb68fa677886d250d024d480de9c8ed32aaf88625c90f6ae7df4af94226a849ead00f8baf71fbb3e111730b51ede2b09100a7875595038dc653bd869139f7d319af9bed1cc4abd2a8c1eb5c69e41c8d0580019c6a8f79eda4687cbb62b4b61446d820c081e622d92ae732c8b15938db87e38c3 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x2cd644782ed2515e847c9f571e31e758 Tue May 13 08:19:06 2014 : Debug: (2) Finished request 2. Tue May 13 08:19:06 2014 : Debug: Waking up in 0.2 seconds. Tue May 13 08:19:07 2014 : Debug: Waking up in 4.6 seconds. rad_recv: Access-Request packet from host 10.7.255.75 port 32806, id=130, length=387 User-Name = 'anonymous' NAS-IP-Address = 10.78.255.11 NAS-Port = 0 NAS-Identifier = '10.7.255.75' NAS-Port-Type = Wireless-802.11 Calling-Station-Id = '002100DB0DC5' Called-Station-Id = '000B866E4C48' Service-Type = Login-User Framed-MTU = 1100 EAP-Message = 0x020400c81580000000be1603010086100000820080e7d6e05c9453f0d49eed693b8210d016c81ebaf411552e2900bf3c30ceb9a37a8efdd287fbe13a7813331a96aeabfdb91641bea7fdbd0376e793ce362583f32c433eb4fc7d5def3115978577290d696369433b8233d292fc7ef16224ef677faa94d97df9514fdf49412c1b738a23abda5b341990691d4e6e4b2d4fa82be885431403010001011603010028fa7268d3dafede71b23977c9bfb546992ce43458cc84be9a1f6fea0d3c4ae45479186f466f1cc4f0 State = 0x2cd644782ed2515e847c9f571e31e758 Aruba-Essid-Name = 'otptest' Aruba-Location-Id = '1.14.25' Aruba-AP-Group = 'tys-low01' Message-Authenticator = 0xb873cbd0150fda519ebe0f34381c99a1 Tue May 13 08:19:07 2014 : Debug: (3) # Executing section authorize from file /usr/local/freeradius-3.0.2/etc/raddb/radiusd.conf Tue May 13 08:19:07 2014 : Debug: (3) authorize { Tue May 13 08:19:07 2014 : Debug: (3) modsingle[authorize]: calling eap (rlm_eap) for request 3 Tue May 13 08:19:07 2014 : Debug: (3) eap : EAP packet type response id 4 length 200 Tue May 13 08:19:07 2014 : Debug: (3) eap : Continuing tunnel setup. Tue May 13 08:19:07 2014 : Debug: (3) modsingle[authorize]: returned from eap (rlm_eap) for request 3 Tue May 13 08:19:07 2014 : Debug: (3) [eap] = ok Tue May 13 08:19:07 2014 : Debug: (3) } # authorize = ok Tue May 13 08:19:07 2014 : Debug: (3) Found Auth-Type = EAP Tue May 13 08:19:07 2014 : Debug: (3) # Executing group from file /usr/local/freeradius-3.0.2/etc/raddb/radiusd.conf Tue May 13 08:19:07 2014 : Debug: (3) authenticate { Tue May 13 08:19:07 2014 : Debug: (3) modsingle[authenticate]: calling eap (rlm_eap) for request 3 Tue May 13 08:19:07 2014 : Debug: (3) eap : Expiring EAP session with state 0x2cd644782ed2515e Tue May 13 08:19:07 2014 : Debug: (3) eap : Finished EAP session with state 0x2cd644782ed2515e Tue May 13 08:19:07 2014 : Debug: (3) eap : Previous EAP request found for state 0x2cd644782ed2515e, released from the list Tue May 13 08:19:07 2014 : Debug: (3) eap : Peer sent TTLS (21) Tue May 13 08:19:07 2014 : Debug: (3) eap : EAP TTLS (21) Tue May 13 08:19:07 2014 : Debug: (3) eap : Calling eap_ttls to process EAP data Tue May 13 08:19:07 2014 : Debug: (3) eap_ttls : Authenticate Tue May 13 08:19:07 2014 : Debug: (3) eap_ttls : processing EAP-TLS Tue May 13 08:19:07 2014 : Debug: TLS Length 190 Tue May 13 08:19:07 2014 : Debug: (3) eap_ttls : Length Included Tue May 13 08:19:07 2014 : Debug: (3) eap_ttls : eaptls_verify returned 11 Tue May 13 08:19:07 2014 : Debug: (3) eap_ttls : <<< TLS 1.0 Handshake [length 0086], ClientKeyExchange Tue May 13 08:19:07 2014 : Debug: (3) eap_ttls : TLS_accept: SSLv3 read client key exchange A Tue May 13 08:19:07 2014 : Debug: (3) eap_ttls : <<< TLS 1.0 ChangeCipherSpec [length 0001] Tue May 13 08:19:07 2014 : Debug: (3) eap_ttls : <<< TLS 1.0 Handshake [length 0010], Finished Tue May 13 08:19:07 2014 : Debug: (3) eap_ttls : TLS_accept: SSLv3 read finished A Tue May 13 08:19:07 2014 : Debug: (3) eap_ttls : >>> TLS 1.0 ChangeCipherSpec [length 0001] Tue May 13 08:19:07 2014 : Debug: (3) eap_ttls : TLS_accept: SSLv3 write change cipher spec A Tue May 13 08:19:07 2014 : Debug: (3) eap_ttls : >>> TLS 1.0 Handshake [length 0010], Finished Tue May 13 08:19:07 2014 : Debug: (3) eap_ttls : TLS_accept: SSLv3 write finished A Tue May 13 08:19:07 2014 : Debug: (3) eap_ttls : TLS_accept: SSLv3 flush data Tue May 13 08:19:07 2014 : Debug: (3) eap_ttls : (other): SSL negotiation finished successfully Tue May 13 08:19:07 2014 : Debug: SSL Connection Established Tue May 13 08:19:07 2014 : Debug: (3) eap_ttls : eaptls_process returned 13 Tue May 13 08:19:07 2014 : Debug: (3) eap : New EAP session, adding 'State' attribute to reply 0x2cd644782fd3515e Tue May 13 08:19:07 2014 : Debug: (3) modsingle[authenticate]: returned from eap (rlm_eap) for request 3 Tue May 13 08:19:07 2014 : Debug: (3) [eap] = handled Tue May 13 08:19:07 2014 : Debug: (3) } # authenticate = handled Sending Access-Challenge of id 130 from 10.33.22.38 port 18120 to 10.7.255.75 port 32806 EAP-Message = 0x0105003d158000000033140301000101160301002832bfa862496539232f5a2e1b5a90d1eeca3d670447c8b35865ea7911bb87e467101508eddad1e3a4 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x2cd644782fd3515e847c9f571e31e758 Tue May 13 08:19:07 2014 : Debug: (3) Finished request 3. Tue May 13 08:19:07 2014 : Debug: Waking up in 0.3 seconds. Tue May 13 08:19:07 2014 : Debug: Waking up in 4.2 seconds. rad_recv: Access-Request packet from host 10.7.255.75 port 32806, id=131, length=258 User-Name = 'anonymous' NAS-IP-Address = 10.78.255.11 NAS-Port = 0 NAS-Identifier = '10.7.255.75' NAS-Port-Type = Wireless-802.11 Calling-Station-Id = '002100DB0DC5' Called-Station-Id = '000B866E4C48' Service-Type = Login-User Framed-MTU = 1100 EAP-Message = 0x0205004715800000003d1703010038dfa6411ddcb262e8133833ae94a13c2ab8de58f66d96dcb90af6e8a19a6f5f8b11edd4d6248915f7e0b6ca5abd7c1a5f9ee032442105ca3e State = 0x2cd644782fd3515e847c9f571e31e758 Aruba-Essid-Name = 'otptest' Aruba-Location-Id = '1.14.25' Aruba-AP-Group = 'tys-low01' Message-Authenticator = 0xc8c0511d5f1bbbb0406e5fad8b40a443 Tue May 13 08:19:08 2014 : Debug: (4) # Executing section authorize from file /usr/local/freeradius-3.0.2/etc/raddb/radiusd.conf Tue May 13 08:19:08 2014 : Debug: (4) authorize { Tue May 13 08:19:08 2014 : Debug: (4) modsingle[authorize]: calling eap (rlm_eap) for request 4 Tue May 13 08:19:08 2014 : Debug: (4) eap : EAP packet type response id 5 length 71 Tue May 13 08:19:08 2014 : Debug: (4) eap : Continuing tunnel setup. Tue May 13 08:19:08 2014 : Debug: (4) modsingle[authorize]: returned from eap (rlm_eap) for request 4 Tue May 13 08:19:08 2014 : Debug: (4) [eap] = ok Tue May 13 08:19:08 2014 : Debug: (4) } # authorize = ok Tue May 13 08:19:08 2014 : Debug: (4) Found Auth-Type = EAP Tue May 13 08:19:08 2014 : Debug: (4) # Executing group from file /usr/local/freeradius-3.0.2/etc/raddb/radiusd.conf Tue May 13 08:19:08 2014 : Debug: (4) authenticate { Tue May 13 08:19:08 2014 : Debug: (4) modsingle[authenticate]: calling eap (rlm_eap) for request 4 Tue May 13 08:19:08 2014 : Debug: (4) eap : Expiring EAP session with state 0x2cd644782fd3515e Tue May 13 08:19:08 2014 : Debug: (4) eap : Finished EAP session with state 0x2cd644782fd3515e Tue May 13 08:19:08 2014 : Debug: (4) eap : Previous EAP request found for state 0x2cd644782fd3515e, released from the list Tue May 13 08:19:08 2014 : Debug: (4) eap : Peer sent TTLS (21) Tue May 13 08:19:08 2014 : Debug: (4) eap : EAP TTLS (21) Tue May 13 08:19:08 2014 : Debug: (4) eap : Calling eap_ttls to process EAP data Tue May 13 08:19:08 2014 : Debug: (4) eap_ttls : Authenticate Tue May 13 08:19:08 2014 : Debug: (4) eap_ttls : processing EAP-TLS Tue May 13 08:19:08 2014 : Debug: TLS Length 61 Tue May 13 08:19:08 2014 : Debug: (4) eap_ttls : Length Included Tue May 13 08:19:08 2014 : Debug: (4) eap_ttls : eaptls_verify returned 11 Tue May 13 08:19:08 2014 : Debug: (4) eap_ttls : eaptls_process returned 7 Tue May 13 08:19:08 2014 : Debug: (4) eap_ttls : Session established. Proceeding to decode tunneled attributes. Tue May 13 08:19:08 2014 : Debug: (4) eap_ttls : Got tunneled request User-Name = '1234567' User-Password = '1' Tue May 13 08:19:08 2014 : Debug: (4) eap_ttls : Sending tunneled request User-Name = '1234567' User-Password = '1' server inner-tunnel { Tue May 13 08:19:08 2014 : Debug: (4) # Executing section authorize from file /usr/local/freeradius-3.0.2/etc/raddb/radiusd.conf Tue May 13 08:19:08 2014 : Debug: (4) authorize { Tue May 13 08:19:08 2014 : Debug: (4) update control { Tue May 13 08:19:08 2014 : Debug: (4) Proxy-To-Realm := 'tinyradius' Tue May 13 08:19:08 2014 : Debug: (4) ::: FROM 1 TO 0 MAX 1 Tue May 13 08:19:08 2014 : Debug: (4) ::: Examining Proxy-To-Realm Tue May 13 08:19:08 2014 : Debug: (4) ::: APPENDING Proxy-To-Realm FROM 0 TO 0 Tue May 13 08:19:08 2014 : Debug: (4) ::: TO in 0 out 1 Tue May 13 08:19:08 2014 : Debug: (4) ::: to[0] = Proxy-To-Realm Tue May 13 08:19:08 2014 : Debug: (4) } # update control = noop Tue May 13 08:19:08 2014 : Debug: (4) } # authorize = noop } # server inner-tunnel Tue May 13 08:19:08 2014 : Debug: (4) eap_ttls : Got tunneled reply code 0 Tue May 13 08:19:08 2014 : Debug: (4) eap_ttls : Tunneled authentication will be proxied to tinyradius Tue May 13 08:19:08 2014 : Debug: (4) eap : Tunneled session will be proxied. Not doing EAP. Tue May 13 08:19:08 2014 : Debug: (4) modsingle[authenticate]: returned from eap (rlm_eap) for request 4 Tue May 13 08:19:08 2014 : Debug: (4) [eap] = handled Tue May 13 08:19:08 2014 : Debug: (4) } # authenticate = handled Tue May 13 08:19:08 2014 : Debug: (4) Empty pre-proxy section. Using default return values. Tue May 13 08:19:08 2014 : Debug: (4) proxy: Trying to allocate ID (0/2) Tue May 13 08:19:08 2014 : Debug: (4) proxy: request is now in proxy hash Tue May 13 08:19:08 2014 : Debug: (4) proxy: allocating destination 127.0.0.1 port 18160 - Id 112 Tue May 13 08:19:08 2014 : Debug: (4) Proxying request to home server 127.0.0.1 port 18160 Sending Access-Request of id 112 from 0.0.0.0 port 59886 to 127.0.0.1 port 18160 User-Name = '1234567' User-Password = '1' Message-Authenticator := 0x00 Proxy-State = 0x313331 Tue May 13 08:19:08 2014 : Debug: Waking up in 0.3 seconds. rad_recv: Access-Accept packet from host 127.0.0.1 port 18160, id=112, length=20 Tue May 13 08:19:08 2014 : Debug: (4) proxy: request is no longer in proxy hash Tue May 13 08:19:08 2014 : Debug: (4) # Executing section post-proxy from file /usr/local/freeradius-3.0.2/etc/raddb/radiusd.conf Tue May 13 08:19:08 2014 : Debug: (4) post-proxy { Tue May 13 08:19:08 2014 : Debug: (4) modsingle[post-proxy]: calling eap (rlm_eap) for request 4 Tue May 13 08:19:08 2014 : Debug: (4) eap : Doing post-proxy callback Tue May 13 08:19:08 2014 : Debug: (4) eap : Passing reply from proxy back into the tunnel. server inner-tunnel { Tue May 13 08:19:08 2014 : Debug: (4) Empty post-auth section. Using default return values. Tue May 13 08:19:08 2014 : Debug: (4) eap : post-auth returns 2 } # server inner-tunnel Tue May 13 08:19:08 2014 : Debug: (4) eap : Final reply from tunneled session code 2 Tue May 13 08:19:08 2014 : Debug: (4) eap : Got reply 2 Tue May 13 08:19:08 2014 : Debug: (4) eap : Got tunneled Access-Accept Tue May 13 08:19:08 2014 : Debug: (4) eap : Reply was OK Tue May 13 08:19:08 2014 : Debug: (4) eap : Freeing handler Tue May 13 08:19:08 2014 : Debug: (4) modsingle[post-proxy]: returned from eap (rlm_eap) for request 4 Tue May 13 08:19:08 2014 : Debug: (4) [eap] = ok Tue May 13 08:19:08 2014 : Debug: (4) } # post-proxy = ok Tue May 13 08:19:08 2014 : Debug: (4) Found Auth-Type = EAP Tue May 13 08:19:08 2014 : Debug: (4) Found Auth-Type = Accept Tue May 13 08:19:08 2014 : ERROR: (4) Warning: Found 2 auth-types on request for user 'anonymous' Tue May 13 08:19:08 2014 : Debug: (4) Auth-Type = Accept, accepting the user Tue May 13 08:19:08 2014 : Debug: (4) Empty post-auth section. Using default return values. Sending Access-Accept of id 131 from 10.33.22.38 port 18120 to 10.7.255.75 port 32806 MS-MPPE-Recv-Key = 0xb37c7d62c03477a95524bf59a303c37d036807d8303c5769e47e9f82dac31f45 MS-MPPE-Send-Key = 0x9c4f772273279ecde8e70c52b2b68d7800fe8cba4d876500f32e793fd82b0c60 EAP-Message = 0x03050004 Message-Authenticator = 0x00000000000000000000000000000000 User-Name = 'anonymous' Tue May 13 08:19:08 2014 : Debug: (4) Finished request 4. Tue May 13 08:19:08 2014 : Debug: Waking up in 0.3 seconds. Tue May 13 08:19:09 2014 : Debug: Waking up in 2.4 seconds. Tue May 13 08:19:11 2014 : Debug: (0) Cleaning up request packet ID 127 with timestamp +11 Tue May 13 08:19:11 2014 : Debug: (1) Cleaning up request packet ID 128 with timestamp +11 Tue May 13 08:19:11 2014 : Debug: (2) Cleaning up request packet ID 129 with timestamp +11 Tue May 13 08:19:11 2014 : Debug: Waking up in 0.3 seconds. Tue May 13 08:19:12 2014 : Debug: (3) Cleaning up request packet ID 130 with timestamp +12 Tue May 13 08:19:12 2014 : Debug: Waking up in 1.8 seconds. Tue May 13 08:19:13 2014 : Debug: (4) Cleaning up request packet ID 131 with timestamp +13 Tue May 13 08:19:13 2014 : Info: Ready to process requests. rad_recv: Access-Request packet from host 10.7.255.75 port 32806, id=132, length=183 User-Name = 'anonymous' NAS-IP-Address = 10.78.255.11 NAS-Port = 0 NAS-Identifier = '10.7.255.75' NAS-Port-Type = Wireless-802.11 Calling-Station-Id = '002100DB0DC5' Called-Station-Id = '000B866E4C48' Service-Type = Login-User Framed-MTU = 1100 EAP-Message = 0x0201000e01616e6f6e796d6f7573 Aruba-Essid-Name = 'otptest' Aruba-Location-Id = '1.14.25' Aruba-AP-Group = 'tys-low01' Message-Authenticator = 0x7bdef0f84856d05189a5b5d4b7915a01 Tue May 13 08:20:33 2014 : Debug: (5) # Executing section authorize from file /usr/local/freeradius-3.0.2/etc/raddb/radiusd.conf Tue May 13 08:20:33 2014 : Debug: (5) authorize { Tue May 13 08:20:33 2014 : Debug: (5) modsingle[authorize]: calling eap (rlm_eap) for request 5 Tue May 13 08:20:33 2014 : Debug: (5) eap : EAP packet type response id 1 length 14 Tue May 13 08:20:33 2014 : Debug: (5) eap : EAP-Identity reply, returning 'ok' so we can short-circuit the rest of authorize Tue May 13 08:20:33 2014 : Debug: (5) modsingle[authorize]: returned from eap (rlm_eap) for request 5 Tue May 13 08:20:33 2014 : Debug: (5) [eap] = ok Tue May 13 08:20:33 2014 : Debug: (5) } # authorize = ok Tue May 13 08:20:33 2014 : Debug: (5) Found Auth-Type = EAP Tue May 13 08:20:33 2014 : Debug: (5) # Executing group from file /usr/local/freeradius-3.0.2/etc/raddb/radiusd.conf Tue May 13 08:20:33 2014 : Debug: (5) authenticate { Tue May 13 08:20:33 2014 : Debug: (5) modsingle[authenticate]: calling eap (rlm_eap) for request 5 Tue May 13 08:20:33 2014 : Debug: (5) eap : Peer sent Identity (1) Tue May 13 08:20:33 2014 : Debug: (5) eap : Calling eap_ttls to process EAP data Tue May 13 08:20:33 2014 : Debug: (5) eap_ttls : Initiate Tue May 13 08:20:33 2014 : Debug: (5) eap_ttls : Start returned 1 Tue May 13 08:20:33 2014 : Debug: (5) eap : New EAP session, adding 'State' attribute to reply 0xb9b6933bb9b486dc Tue May 13 08:20:33 2014 : Debug: (5) modsingle[authenticate]: returned from eap (rlm_eap) for request 5 Tue May 13 08:20:33 2014 : Debug: (5) [eap] = handled Tue May 13 08:20:33 2014 : Debug: (5) } # authenticate = handled Sending Access-Challenge of id 132 from 10.33.22.38 port 18120 to 10.7.255.75 port 32806 EAP-Message = 0x010200061520 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xb9b6933bb9b486dca08ab069110ad539 Tue May 13 08:20:33 2014 : Debug: (5) Finished request 5. Tue May 13 08:20:33 2014 : Debug: Waking up in 0.3 seconds. rad_recv: Access-Request packet from host 10.7.255.75 port 32806, id=133, length=287 User-Name = 'anonymous' NAS-IP-Address = 10.78.255.11 NAS-Port = 0 NAS-Identifier = '10.7.255.75' NAS-Port-Type = Wireless-802.11 Calling-Station-Id = '002100DB0DC5' Called-Station-Id = '000B866E4C48' Service-Type = Login-User Framed-MTU = 1100 EAP-Message = 0x0202006415800000005a1603010055010000510301537159a37b79cd1d08d56d250f2b0a0e096ddcf7b930439627ec8c11fb7547de00002a00160013006600150012000a0005000400070009006300650060006200610064001400110003000600080100 State = 0xb9b6933bb9b486dca08ab069110ad539 Aruba-Essid-Name = 'otptest' Aruba-Location-Id = '1.14.25' Aruba-AP-Group = 'tys-low01' Message-Authenticator = 0xd133446c5e988938a813606ae65825da Tue May 13 08:20:33 2014 : Debug: (6) # Executing section authorize from file /usr/local/freeradius-3.0.2/etc/raddb/radiusd.conf Tue May 13 08:20:33 2014 : Debug: (6) authorize { Tue May 13 08:20:33 2014 : Debug: (6) modsingle[authorize]: calling eap (rlm_eap) for request 6 Tue May 13 08:20:33 2014 : Debug: (6) eap : EAP packet type response id 2 length 100 Tue May 13 08:20:33 2014 : Debug: (6) eap : Continuing tunnel setup. Tue May 13 08:20:33 2014 : Debug: (6) modsingle[authorize]: returned from eap (rlm_eap) for request 6 Tue May 13 08:20:33 2014 : Debug: (6) [eap] = ok Tue May 13 08:20:33 2014 : Debug: (6) } # authorize = ok Tue May 13 08:20:33 2014 : Debug: (6) Found Auth-Type = EAP Tue May 13 08:20:33 2014 : Debug: (6) # Executing group from file /usr/local/freeradius-3.0.2/etc/raddb/radiusd.conf Tue May 13 08:20:33 2014 : Debug: (6) authenticate { Tue May 13 08:20:33 2014 : Debug: (6) modsingle[authenticate]: calling eap (rlm_eap) for request 6 Tue May 13 08:20:33 2014 : Debug: (6) eap : Expiring EAP session with state 0xb9b6933bb9b486dc Tue May 13 08:20:33 2014 : Debug: (6) eap : Finished EAP session with state 0xb9b6933bb9b486dc Tue May 13 08:20:33 2014 : Debug: (6) eap : Previous EAP request found for state 0xb9b6933bb9b486dc, released from the list Tue May 13 08:20:33 2014 : Debug: (6) eap : Peer sent TTLS (21) Tue May 13 08:20:33 2014 : Debug: (6) eap : EAP TTLS (21) Tue May 13 08:20:33 2014 : Debug: (6) eap : Calling eap_ttls to process EAP data Tue May 13 08:20:33 2014 : Debug: (6) eap_ttls : Authenticate Tue May 13 08:20:33 2014 : Debug: (6) eap_ttls : processing EAP-TLS Tue May 13 08:20:33 2014 : Debug: TLS Length 90 Tue May 13 08:20:33 2014 : Debug: (6) eap_ttls : Length Included Tue May 13 08:20:33 2014 : Debug: (6) eap_ttls : eaptls_verify returned 11 Tue May 13 08:20:33 2014 : Debug: (6) eap_ttls : (other): before/accept initialization Tue May 13 08:20:33 2014 : Debug: (6) eap_ttls : TLS_accept: before/accept initialization Tue May 13 08:20:33 2014 : Debug: (6) eap_ttls : <<< TLS 1.0 Handshake [length 0055], ClientHello Tue May 13 08:20:33 2014 : Debug: (6) eap_ttls : TLS_accept: SSLv3 read client hello A Tue May 13 08:20:33 2014 : Debug: (6) eap_ttls : >>> TLS 1.0 Handshake [length 002a], ServerHello Tue May 13 08:20:33 2014 : Debug: (6) eap_ttls : TLS_accept: SSLv3 write server hello A Tue May 13 08:20:33 2014 : Debug: (6) eap_ttls : >>> TLS 1.0 Handshake [length 03cc], Certificate Tue May 13 08:20:33 2014 : Debug: (6) eap_ttls : TLS_accept: SSLv3 write certificate A Tue May 13 08:20:33 2014 : Debug: (6) eap_ttls : >>> TLS 1.0 Handshake [length 020d], ServerKeyExchange Tue May 13 08:20:33 2014 : Debug: (6) eap_ttls : TLS_accept: SSLv3 write key exchange A Tue May 13 08:20:33 2014 : Debug: (6) eap_ttls : >>> TLS 1.0 Handshake [length 0004], ServerHelloDone Tue May 13 08:20:33 2014 : Debug: (6) eap_ttls : TLS_accept: SSLv3 write server done A Tue May 13 08:20:33 2014 : Debug: (6) eap_ttls : TLS_accept: SSLv3 flush data Tue May 13 08:20:33 2014 : Debug: (6) eap_ttls : TLS_accept: Need to read more data: SSLv3 read client certificate A Tue May 13 08:20:33 2014 : Debug: In SSL Handshake Phase Tue May 13 08:20:33 2014 : Debug: In SSL Accept mode Tue May 13 08:20:33 2014 : Debug: (6) eap_ttls : eaptls_process returned 13 Tue May 13 08:20:33 2014 : Debug: (6) eap : New EAP session, adding 'State' attribute to reply 0xb9b6933bb8b586dc Tue May 13 08:20:33 2014 : Debug: (6) modsingle[authenticate]: returned from eap (rlm_eap) for request 6 Tue May 13 08:20:33 2014 : Debug: (6) [eap] = handled Tue May 13 08:20:33 2014 : Debug: (6) } # authenticate = handled Sending Access-Challenge of id 133 from 10.33.22.38 port 18120 to 10.7.255.75 port 32806 EAP-Message = 0x0103040015c00000061b160301002a0200002603010bdc44587d59355272d4a4b33f65770ba6e60780984dc49be79f16617fa69e9f0000160016030103cc0b0003c80003c50003c2308203be308202a6020900d8e196b535b385dc300d06092a864886f70d01010505003081a0310b3009060355040613024a50310e300c06035504080c05546f6b796f310e300c06035504070c054368756f753110300e060355040a0c074e545444415441310c300a060355040b0c0349544d3128302606035504030c1f746f702d6f74707261643531762e6d6e672e6e7474646174612e636f2e6a703127302506092a864886f70d0109011618706f73746d6173746572406e7474646174612e636f2e6a70301e170d3134303431393131343534365a170d3135303431393131343534365a3081a0310b3009060355040613024a50310e300c06035504080c05546f6b796f310e300c06035504070c054368756f753110300e060355040a0c074e545444415441310c300a060355040b0c0349544d3128302606035504030c1f746f702d6f74707261643531762e6d6e672e6e7474646174612e636f2e6a703127302506092a864886f70d0109011618706f73746d6173746572406e7474646174612e636f2e6a7030820122300d06092a864886f70d01010105000382010f003082010a0282010100cbd1213f741 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xb9b6933bb8b586dca08ab069110ad539 Tue May 13 08:20:33 2014 : Debug: (6) Finished request 6. Tue May 13 08:20:33 2014 : Debug: Waking up in 0.2 seconds. rad_recv: Access-Request packet from host 10.7.255.75 port 32806, id=134, length=193 User-Name = 'anonymous' NAS-IP-Address = 10.78.255.11 NAS-Port = 0 NAS-Identifier = '10.7.255.75' NAS-Port-Type = Wireless-802.11 Calling-Station-Id = '002100DB0DC5' Called-Station-Id = '000B866E4C48' Service-Type = Login-User Framed-MTU = 1100 EAP-Message = 0x020300061500 State = 0xb9b6933bb8b586dca08ab069110ad539 Aruba-Essid-Name = 'otptest' Aruba-Location-Id = '1.14.25' Aruba-AP-Group = 'tys-low01' Message-Authenticator = 0xadbf99b14a71060ea108bf3b218f9cf7 Tue May 13 08:20:33 2014 : Debug: (7) # Executing section authorize from file /usr/local/freeradius-3.0.2/etc/raddb/radiusd.conf Tue May 13 08:20:33 2014 : Debug: (7) authorize { Tue May 13 08:20:33 2014 : Debug: (7) modsingle[authorize]: calling eap (rlm_eap) for request 7 Tue May 13 08:20:33 2014 : Debug: (7) eap : EAP packet type response id 3 length 6 Tue May 13 08:20:33 2014 : Debug: (7) eap : Continuing tunnel setup. Tue May 13 08:20:33 2014 : Debug: (7) modsingle[authorize]: returned from eap (rlm_eap) for request 7 Tue May 13 08:20:33 2014 : Debug: (7) [eap] = ok Tue May 13 08:20:33 2014 : Debug: (7) } # authorize = ok Tue May 13 08:20:33 2014 : Debug: (7) Found Auth-Type = EAP Tue May 13 08:20:33 2014 : Debug: (7) # Executing group from file /usr/local/freeradius-3.0.2/etc/raddb/radiusd.conf Tue May 13 08:20:33 2014 : Debug: (7) authenticate { Tue May 13 08:20:33 2014 : Debug: (7) modsingle[authenticate]: calling eap (rlm_eap) for request 7 Tue May 13 08:20:33 2014 : Debug: (7) eap : Expiring EAP session with state 0xb9b6933bb8b586dc Tue May 13 08:20:33 2014 : Debug: (7) eap : Finished EAP session with state 0xb9b6933bb8b586dc Tue May 13 08:20:33 2014 : Debug: (7) eap : Previous EAP request found for state 0xb9b6933bb8b586dc, released from the list Tue May 13 08:20:33 2014 : Debug: (7) eap : Peer sent TTLS (21) Tue May 13 08:20:33 2014 : Debug: (7) eap : EAP TTLS (21) Tue May 13 08:20:33 2014 : Debug: (7) eap : Calling eap_ttls to process EAP data Tue May 13 08:20:33 2014 : Debug: (7) eap_ttls : Authenticate Tue May 13 08:20:33 2014 : Debug: (7) eap_ttls : processing EAP-TLS Tue May 13 08:20:33 2014 : Debug: (7) eap_ttls : Received TLS ACK Tue May 13 08:20:33 2014 : Debug: (7) eap_ttls : Received TLS ACK Tue May 13 08:20:33 2014 : Debug: (7) eap_ttls : ACK handshake fragment handler Tue May 13 08:20:33 2014 : Debug: (7) eap_ttls : eaptls_verify returned 1 Tue May 13 08:20:33 2014 : Debug: (7) eap_ttls : eaptls_process returned 13 Tue May 13 08:20:33 2014 : Debug: (7) eap : New EAP session, adding 'State' attribute to reply 0xb9b6933bbbb286dc Tue May 13 08:20:33 2014 : Debug: (7) modsingle[authenticate]: returned from eap (rlm_eap) for request 7 Tue May 13 08:20:33 2014 : Debug: (7) [eap] = handled Tue May 13 08:20:33 2014 : Debug: (7) } # authenticate = handled Sending Access-Challenge of id 134 from 10.33.22.38 port 18120 to 10.7.255.75 port 32806 EAP-Message = 0x0104022f15800000061b1656ba74fcd8aabc61ca160301020d0c0002090080f9ff408fde4339b038b6d70ffa17ddc5efd2b8a760df3f5f914e5547417d84139c0bdf7692016aba5f138e0f574a062f54f8c3c93a13a9268320eb5ea1cdb6295a102a424aa2bc0a7c058c1ec7466c81acaa48424f451b2ff0a85c87cff71735a1b337edcc5c911b4290f67be096967d7361bd217b976f2c692ef4ce1a7d266300010200803ce60687d012617836e173cf225a7c305c5c83675758c40b47e8815ea902dad95cf4c88fe2f0e0fc389d9c53737e9b29913a6928cfedfb9881868fd35595c9e4ed928dd22cf7d9ebd270a2f33703313d776016b6e690234c5f9df03b0edd316b31e3f36017296a306b4aef37e68425fd08a115ccbbe0d215675c51a3fb8a6d9d0100928cb08fc4d439388701473816fc1d31bcadef6a639389ada0944be0eee7d3fec1a316f0ed4e8386ce8b9859485da3e442521055a5cef97e20b70d12fd07c158ff880097d37227b513c0674a52826ef8889cd3acbece447e2fb58d576239c0e62ae2de4cf118eec3cb524bf97b1b7d56da87eea2d12d2e087aad2e5a27244128486f87177f33e805e6e4f9ccdb74f36fc81da6666f5835ee35871d0b03edf11f47537bd665bd31895bcf0558ab72ddb21ff8088283459b8cc000eea48c0ce93f686781ee970963f4d5da18731d08dc597 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xb9b6933bbbb286dca08ab069110ad539 Tue May 13 08:20:33 2014 : Debug: (7) Finished request 7. Tue May 13 08:20:33 2014 : Debug: Waking up in 0.2 seconds. rad_recv: Access-Request packet from host 10.7.255.75 port 32806, id=135, length=387 User-Name = 'anonymous' NAS-IP-Address = 10.78.255.11 NAS-Port = 0 NAS-Identifier = '10.7.255.75' NAS-Port-Type = Wireless-802.11 Calling-Station-Id = '002100DB0DC5' Called-Station-Id = '000B866E4C48' Service-Type = Login-User Framed-MTU = 1100 EAP-Message = 0x020400c81580000000be16030100861000008200801e2b01b9b526d9ca39f340b134b5528ff46141024f01881b89d5d51341d9b3de6fabb9f9d055f735032f790fb3ef1d81197aaaaf615041c74e2c71e3c1db5d66dd6f5a90db014e11c1b5633401ae2c7abcd967db24c1c13f08fca7101c3ae8d059c49bbe361d7a5122a08f9f21ad520b4d53a756bcd85aebf57917f44000520c14030100010116030100286195f1e7a73e5889ddc38dcd3fd585c61dadf8546ab0fd0890be19c9cd6913b068e536170de1280d State = 0xb9b6933bbbb286dca08ab069110ad539 Aruba-Essid-Name = 'otptest' Aruba-Location-Id = '1.14.25' Aruba-AP-Group = 'tys-low01' Message-Authenticator = 0xbdb20e300c2366483eca8a5b82d762bf Tue May 13 08:20:34 2014 : Debug: (8) # Executing section authorize from file /usr/local/freeradius-3.0.2/etc/raddb/radiusd.conf Tue May 13 08:20:34 2014 : Debug: (8) authorize { Tue May 13 08:20:34 2014 : Debug: (8) modsingle[authorize]: calling eap (rlm_eap) for request 8 Tue May 13 08:20:34 2014 : Debug: (8) eap : EAP packet type response id 4 length 200 Tue May 13 08:20:34 2014 : Debug: (8) eap : Continuing tunnel setup. Tue May 13 08:20:34 2014 : Debug: (8) modsingle[authorize]: returned from eap (rlm_eap) for request 8 Tue May 13 08:20:34 2014 : Debug: (8) [eap] = ok Tue May 13 08:20:34 2014 : Debug: (8) } # authorize = ok Tue May 13 08:20:34 2014 : Debug: (8) Found Auth-Type = EAP Tue May 13 08:20:34 2014 : Debug: (8) # Executing group from file /usr/local/freeradius-3.0.2/etc/raddb/radiusd.conf Tue May 13 08:20:34 2014 : Debug: (8) authenticate { Tue May 13 08:20:34 2014 : Debug: (8) modsingle[authenticate]: calling eap (rlm_eap) for request 8 Tue May 13 08:20:34 2014 : Debug: (8) eap : Expiring EAP session with state 0xb9b6933bbbb286dc Tue May 13 08:20:34 2014 : Debug: (8) eap : Finished EAP session with state 0xb9b6933bbbb286dc Tue May 13 08:20:34 2014 : Debug: (8) eap : Previous EAP request found for state 0xb9b6933bbbb286dc, released from the list Tue May 13 08:20:34 2014 : Debug: (8) eap : Peer sent TTLS (21) Tue May 13 08:20:34 2014 : Debug: (8) eap : EAP TTLS (21) Tue May 13 08:20:34 2014 : Debug: (8) eap : Calling eap_ttls to process EAP data Tue May 13 08:20:34 2014 : Debug: (8) eap_ttls : Authenticate Tue May 13 08:20:34 2014 : Debug: (8) eap_ttls : processing EAP-TLS Tue May 13 08:20:34 2014 : Debug: TLS Length 190 Tue May 13 08:20:34 2014 : Debug: (8) eap_ttls : Length Included Tue May 13 08:20:34 2014 : Debug: (8) eap_ttls : eaptls_verify returned 11 Tue May 13 08:20:34 2014 : Debug: (8) eap_ttls : <<< TLS 1.0 Handshake [length 0086], ClientKeyExchange Tue May 13 08:20:34 2014 : Debug: (8) eap_ttls : TLS_accept: SSLv3 read client key exchange A Tue May 13 08:20:34 2014 : Debug: (8) eap_ttls : <<< TLS 1.0 ChangeCipherSpec [length 0001] Tue May 13 08:20:34 2014 : Debug: (8) eap_ttls : <<< TLS 1.0 Handshake [length 0010], Finished Tue May 13 08:20:34 2014 : Debug: (8) eap_ttls : TLS_accept: SSLv3 read finished A Tue May 13 08:20:34 2014 : Debug: (8) eap_ttls : >>> TLS 1.0 ChangeCipherSpec [length 0001] Tue May 13 08:20:34 2014 : Debug: (8) eap_ttls : TLS_accept: SSLv3 write change cipher spec A Tue May 13 08:20:34 2014 : Debug: (8) eap_ttls : >>> TLS 1.0 Handshake [length 0010], Finished Tue May 13 08:20:34 2014 : Debug: (8) eap_ttls : TLS_accept: SSLv3 write finished A Tue May 13 08:20:34 2014 : Debug: (8) eap_ttls : TLS_accept: SSLv3 flush data Tue May 13 08:20:34 2014 : Debug: (8) eap_ttls : (other): SSL negotiation finished successfully Tue May 13 08:20:34 2014 : Debug: SSL Connection Established Tue May 13 08:20:34 2014 : Debug: (8) eap_ttls : eaptls_process returned 13 Tue May 13 08:20:34 2014 : Debug: (8) eap : New EAP session, adding 'State' attribute to reply 0xb9b6933bbab386dc Tue May 13 08:20:34 2014 : Debug: (8) modsingle[authenticate]: returned from eap (rlm_eap) for request 8 Tue May 13 08:20:34 2014 : Debug: (8) [eap] = handled Tue May 13 08:20:34 2014 : Debug: (8) } # authenticate = handled Sending Access-Challenge of id 135 from 10.33.22.38 port 18120 to 10.7.255.75 port 32806 EAP-Message = 0x0105003d1580000000331403010001011603010028542d18a9356ec77acdeaf3a0e26750b476c989b681736159de406d994f6e8bcc05f7a4b969bdaf6a Message-Authenticator = 0x00000000000000000000000000000000 State = 0xb9b6933bbab386dca08ab069110ad539 Tue May 13 08:20:34 2014 : Debug: (8) Finished request 8. Tue May 13 08:20:34 2014 : Debug: Waking up in 0.2 seconds. Tue May 13 08:20:34 2014 : Debug: Waking up in 4.3 seconds. Tue May 13 08:20:38 2014 : Debug: (5) Cleaning up request packet ID 132 with timestamp +98 Tue May 13 08:20:38 2014 : Debug: (6) Cleaning up request packet ID 133 with timestamp +98 Tue May 13 08:20:38 2014 : Debug: (7) Cleaning up request packet ID 134 with timestamp +98 Tue May 13 08:20:38 2014 : Debug: Waking up in 0.2 seconds. Tue May 13 08:20:39 2014 : Debug: (8) Cleaning up request packet ID 135 with timestamp +99 Tue May 13 08:20:39 2014 : Info: Ready to process requests. rad_recv: Access-Request packet from host 10.7.255.75 port 32806, id=136, length=258 User-Name = 'anonymous' NAS-IP-Address = 10.78.255.11 NAS-Port = 0 NAS-Identifier = '10.7.255.75' NAS-Port-Type = Wireless-802.11 Calling-Station-Id = '002100DB0DC5' Called-Station-Id = '000B866E4C48' Service-Type = Login-User Framed-MTU = 1100 EAP-Message = 0x0205004715800000003d170301003809bab38229f251783d96fd0f0497d155d5e64498207b70403da0502b42fa87b344a31f8652d0a99abef48549113731a67e6ed3811316a502 State = 0xb9b6933bbab386dca08ab069110ad539 Aruba-Essid-Name = 'otptest' Aruba-Location-Id = '1.14.25' Aruba-AP-Group = 'tys-low01' Message-Authenticator = 0x124536dfc7dba4f0b4f9f9028c4eb7fb Tue May 13 08:21:02 2014 : Debug: (9) # Executing section authorize from file /usr/local/freeradius-3.0.2/etc/raddb/radiusd.conf Tue May 13 08:21:02 2014 : Debug: (9) authorize { Tue May 13 08:21:02 2014 : Debug: (9) modsingle[authorize]: calling eap (rlm_eap) for request 9 Tue May 13 08:21:02 2014 : Debug: (9) eap : EAP packet type response id 5 length 71 Tue May 13 08:21:02 2014 : Debug: (9) eap : Continuing tunnel setup. Tue May 13 08:21:02 2014 : Debug: (9) modsingle[authorize]: returned from eap (rlm_eap) for request 9 Tue May 13 08:21:02 2014 : Debug: (9) [eap] = ok Tue May 13 08:21:02 2014 : Debug: (9) } # authorize = ok Tue May 13 08:21:02 2014 : Debug: (9) Found Auth-Type = EAP Tue May 13 08:21:02 2014 : Debug: (9) # Executing group from file /usr/local/freeradius-3.0.2/etc/raddb/radiusd.conf Tue May 13 08:21:02 2014 : Debug: (9) authenticate { Tue May 13 08:21:02 2014 : Debug: (9) modsingle[authenticate]: calling eap (rlm_eap) for request 9 Tue May 13 08:21:02 2014 : Debug: (9) eap : Expiring EAP session with state 0xb9b6933bbab386dc Tue May 13 08:21:02 2014 : Debug: (9) eap : Finished EAP session with state 0xb9b6933bbab386dc Tue May 13 08:21:02 2014 : Debug: (9) eap : Previous EAP request found for state 0xb9b6933bbab386dc, released from the list Tue May 13 08:21:02 2014 : Debug: (9) eap : Peer sent TTLS (21) Tue May 13 08:21:02 2014 : Debug: (9) eap : EAP TTLS (21) Tue May 13 08:21:02 2014 : Debug: (9) eap : Calling eap_ttls to process EAP data Tue May 13 08:21:02 2014 : Debug: (9) eap_ttls : Authenticate Tue May 13 08:21:02 2014 : Debug: (9) eap_ttls : processing EAP-TLS Tue May 13 08:21:02 2014 : Debug: TLS Length 61 Tue May 13 08:21:02 2014 : Debug: (9) eap_ttls : Length Included Tue May 13 08:21:02 2014 : Debug: (9) eap_ttls : eaptls_verify returned 11 Tue May 13 08:21:02 2014 : Debug: (9) eap_ttls : eaptls_process returned 7 Tue May 13 08:21:02 2014 : Debug: (9) eap_ttls : Session established. Proceeding to decode tunneled attributes. Tue May 13 08:21:02 2014 : Debug: (9) eap_ttls : Got tunneled request User-Name = '1234567' User-Password = '2' Tue May 13 08:21:02 2014 : Debug: (9) eap_ttls : Sending tunneled request User-Name = '1234567' User-Password = '2' server inner-tunnel { Tue May 13 08:21:02 2014 : Debug: (9) # Executing section authorize from file /usr/local/freeradius-3.0.2/etc/raddb/radiusd.conf Tue May 13 08:21:02 2014 : Debug: (9) authorize { Tue May 13 08:21:02 2014 : Debug: (9) update control { Tue May 13 08:21:02 2014 : Debug: (9) Proxy-To-Realm := 'tinyradius' Tue May 13 08:21:02 2014 : Debug: (9) ::: FROM 1 TO 0 MAX 1 Tue May 13 08:21:02 2014 : Debug: (9) ::: Examining Proxy-To-Realm Tue May 13 08:21:02 2014 : Debug: (9) ::: APPENDING Proxy-To-Realm FROM 0 TO 0 Tue May 13 08:21:02 2014 : Debug: (9) ::: TO in 0 out 1 Tue May 13 08:21:02 2014 : Debug: (9) ::: to[0] = Proxy-To-Realm Tue May 13 08:21:02 2014 : Debug: (9) } # update control = noop Tue May 13 08:21:02 2014 : Debug: (9) } # authorize = noop } # server inner-tunnel Tue May 13 08:21:02 2014 : Debug: (9) eap_ttls : Got tunneled reply code 0 Tue May 13 08:21:02 2014 : Debug: (9) eap_ttls : Tunneled authentication will be proxied to tinyradius Tue May 13 08:21:02 2014 : Debug: (9) eap : Tunneled session will be proxied. Not doing EAP. Tue May 13 08:21:02 2014 : Debug: (9) modsingle[authenticate]: returned from eap (rlm_eap) for request 9 Tue May 13 08:21:02 2014 : Debug: (9) [eap] = handled Tue May 13 08:21:02 2014 : Debug: (9) } # authenticate = handled Tue May 13 08:21:02 2014 : Debug: (9) Empty pre-proxy section. Using default return values. Tue May 13 08:21:02 2014 : Debug: (9) proxy: Trying to allocate ID (0/2) Tue May 13 08:21:02 2014 : Debug: (9) proxy: request is now in proxy hash Tue May 13 08:21:02 2014 : Debug: (9) proxy: allocating destination 127.0.0.1 port 18160 - Id 18 Tue May 13 08:21:02 2014 : Debug: (9) Proxying request to home server 127.0.0.1 port 18160 Sending Access-Request of id 18 from 0.0.0.0 port 59886 to 127.0.0.1 port 18160 User-Name = '1234567' User-Password = '2' Message-Authenticator := 0x00 Proxy-State = 0x313336 Tue May 13 08:21:02 2014 : Debug: Waking up in 0.3 seconds. rad_recv: Access-Accept packet from host 127.0.0.1 port 18160, id=18, length=20 Tue May 13 08:21:02 2014 : Debug: (9) proxy: request is no longer in proxy hash Tue May 13 08:21:02 2014 : Debug: (9) # Executing section post-proxy from file /usr/local/freeradius-3.0.2/etc/raddb/radiusd.conf Tue May 13 08:21:02 2014 : Debug: (9) post-proxy { Tue May 13 08:21:02 2014 : Debug: (9) modsingle[post-proxy]: calling eap (rlm_eap) for request 9 Tue May 13 08:21:02 2014 : Debug: (9) eap : Doing post-proxy callback Tue May 13 08:21:02 2014 : Debug: (9) eap : Passing reply from proxy back into the tunnel. server inner-tunnel { Tue May 13 08:21:02 2014 : Debug: (9) Empty post-auth section. Using default return values. Tue May 13 08:21:02 2014 : Debug: (9) eap : post-auth returns 2 } # server inner-tunnel Tue May 13 08:21:02 2014 : Debug: (9) eap : Final reply from tunneled session code 2 Tue May 13 08:21:02 2014 : Debug: (9) eap : Got reply 2 Tue May 13 08:21:02 2014 : Debug: (9) eap : Got tunneled Access-Accept Tue May 13 08:21:02 2014 : Debug: (9) eap : Reply was OK Tue May 13 08:21:02 2014 : Debug: (9) eap : Freeing handler Tue May 13 08:21:02 2014 : Debug: (9) modsingle[post-proxy]: returned from eap (rlm_eap) for request 9 Tue May 13 08:21:02 2014 : Debug: (9) [eap] = ok Tue May 13 08:21:02 2014 : Debug: (9) } # post-proxy = ok Tue May 13 08:21:02 2014 : Debug: (9) Found Auth-Type = EAP Tue May 13 08:21:02 2014 : Debug: (9) Found Auth-Type = Accept Tue May 13 08:21:02 2014 : ERROR: (9) Warning: Found 2 auth-types on request for user 'anonymous' Tue May 13 08:21:02 2014 : Debug: (9) Auth-Type = Accept, accepting the user Tue May 13 08:21:02 2014 : Debug: (9) Empty post-auth section. Using default return values. Sending Access-Accept of id 136 from 10.33.22.38 port 18120 to 10.7.255.75 port 32806 MS-MPPE-Recv-Key = 0x163e7f657610b516edacfba09f5b7b632031243f9596a43c243c4df8e6ea1314 MS-MPPE-Send-Key = 0xdbd7e58b35ccab0e27174b1fc627ecbdddd234311a0e1cd884181419845388cf EAP-Message = 0x03050004 Message-Authenticator = 0x00000000000000000000000000000000 User-Name = 'anonymous' Tue May 13 08:21:02 2014 : Debug: (9) Finished request 9. Tue May 13 08:21:02 2014 : Debug: Waking up in 0.3 seconds. Tue May 13 08:21:03 2014 : Debug: Waking up in 4.6 seconds. Tue May 13 08:21:07 2014 : Debug: (9) Cleaning up request packet ID 136 with timestamp +127 Tue May 13 08:21:07 2014 : Info: Ready to process requests. Regards. --- Kouki Hashimoto hashimotoku at nttdata.co.jp

2 1

Motorola switch auth
by Walter Herrera 12 May '14

12 May '14

Hi! a'm using freeradius 1.1.7 with ldap, i have a motorola switch, that work with radius, for motorola switches i need configure an id code permision in the auth process, how i can configure these? or where i can find information for this? thanks. Walter Herrera.

3 2

RE: SQL - How to use MSSQL for Authentication and MySQL for
by Mike Poole 12 May '14

12 May '14

Greetings, * I have searched for some time but cannot seem to find an answer to this, but I am sure it can be done. * I use a MSSQL database on a separate server for Authentication and that is working well. * I want to use a MySQL database on a third server for Accounting. * Everything I have searched shows how to configure it for one or the other but not both. * I am trying to find out how to accomplish this, so if anyone has some insight, please do share. * Thanks in advance. * Jer We use two different databases as well. Our setup is on the NAS itself. Point RADIUS auth to one server IP and set RADIUS accouting to the other server. Mike P. *************************************************

3 4

SQL - How to use MSSQL for Authentication and MySQL for Accounting
by Jeremiah Peterson 12 May '14

12 May '14

Greetings, I have searched for some time but cannot seem to find an answer to this, but I am sure it can be done. I use a MSSQL database on a separate server for Authentication and that is working well. I want to use a MySQL database on a third server for Accounting. Everything I have searched shows how to configure it for one or the other but not both. I am trying to find out how to accomplish this, so if anyone has some insight, please do share. Thanks in advance. Jer

1 0

Question about "lower"
by Lucas Diaz 12 May '14

12 May '14

I've got installed freeradius 3.0.3 connected to a firebird database. It is working fine for about a week, but I'm getting my logs filled with following entries: Mon May 12 10:05:38 2014 : Info: rlm_sql (sql): Opening additional connection (1116) Mon May 12 10:05:38 2014 : Info: rlm_sql (sql): Closing connection (1114): Hit idle_timeout, was idle for 577 seconds Mon May 12 10:05:38 2014 : rlm_sql (sql): You probably need to lower "min" Mon May 12 10:05:51 2014 : Info: rlm_sql (sql): Opening additional connection (1117) Mon May 12 10:07:40 2014 : Info: rlm_sql (sql): Closing connection (1116): Hit idle_timeout, was idle for 109 seconds Mon May 12 10:07:40 2014 : rlm_sql (sql): You probably need to lower "min" Mon May 12 10:07:40 2014 : Info: rlm_sql (sql): Closing connection (1115): Hit idle_timeout, was idle for 123 seconds Mon May 12 10:08:12 2014 : Info: rlm_sql (sql): Opening additional connection (1118) Mon May 12 10:08:53 2014 : Info: rlm_sql (sql): Opening additional connection (1119) Mon May 12 10:12:16 2014 : Info: rlm_sql (sql): Closing connection (1118): Hit idle_timeout, was idle for 203 seconds Mon May 12 10:12:16 2014 : rlm_sql (sql): You probably need to lower "min" Mon May 12 10:12:16 2014 : Info: rlm_sql (sql): Closing connection (1117): Hit idle_timeout, was idle for 244 seconds I'd like to know what means " You probably need to lower "min" " Thank you. -- *LUCAS DIAZ | DPTO. REDES* _______________________________________________________ Istilart 255 | Tel.: 02983 513040 C.P. B7500EGE | Tres Arroyos | Bs As | Argentina * *www.eternet.cc <http://www.eternet.cc/> | *ETERNET SISTEMAS *

3 3

AVP EAP-KEY name support in FR
by Srinu Bandari 12 May '14

12 May '14

Hi, We are trying to bring up MACsec with Cisco and FR, and we are stuck because of Radius unable to send EAP-Key-Name AVP. Below is what is expected as per RFC4072 RFC4072 says "A home Diameter server receiving a Diameter-EAP-Request with a Key-Name AVP with non-empty data MUST silently discard the AVP. In addition, the home Diameter server SHOULD include this AVP in Diameter-EAP-Response only if an empty EAP-Key-Name AVP was present in Diameter-EAP-Request." But radius server is not sending EAP-Key-Name AVP (Radius Attribute Type 102) even invalid AVP present in the Diameter-EAP-Request". Below is the debug print of radius Sending Access-Accept of id 647 to 10.20.64.9 port 1645 MS-MPPE-Recv-Key = 0x84e5c624c3bcdeadca3c6210f24bd7b8336921ccc1c58399d397afc75770332c MS-MPPE-Send-Key = 0xa6c4860cc8092c251502f5adc3ee13586e05fe84cbbb8b6793b08d9523d12b1f EAP-Message = 0x03060004 Message-Authenticator = 0x00000000000000000000000000000000 User-Name = "user1" Does anyone have clue on this. Thanks, Srinivas CONFIDENTIALITY NOTICE: This e-mail message, including any attachments, is for the sole use of the intended recipient(s) and may contain confidential and privileged information. Any unauthorized review, use, disclosure or distribution is prohibited. If you are not the intended recipient, please contact the sender by reply e-mail and destroy all copies of the original message.

4 19