Freeradius-Users
Threads by month
- ----- 2026 -----
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2025 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2024 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2023 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2022 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2021 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2020 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2019 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2018 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2017 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2016 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2015 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2014 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2013 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2012 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2011 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2010 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2009 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2008 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2007 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2006 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2005 -----
- December
- November
- October
- September
- August
- July
- June
- May
- 27050 discussions
Configuring a router to query a givenradius server is well and widely
documented, but all of the docs and tuts I've found skip the question
of what to put in the radius server for doing 802.1x authentication.
Can anyone here provide any details?
My goal is username/passwd auth, at least for now.
Thank you.
-JimC
--
James Cloos <cloos(a)jhcloos.com> OpenPGP: 0x997A9F17ED7DAEA6
3
4
Hi,
We have a large deployment of about 600 NAS (mixed openwrt/mikrotik/others). I have noticed that for some records, incorrect acctstoptime was marked while user session was still going on and accounting was happening. So following is the flow -
1. Use login on hotspot, accounting starts2. After sometime (5-7 minutes), acctstoptime populates with a datetime value, while user is surfing3. user keep surfing and accounting keep happening.4. I have run radius in debug mode and captured log, NAS did not send any accounting stop packet.5. I have also observed around 26 records out of 110 current logged in users have same acctstoptime timestamp value and acctterminatecause value as either NULL or 0.
Looks like a query is making incorrect updates. I am using FR 2x an can't update to 3 right now. Have observed following query in logs, which might be an issue -
UPDATE radacct SET acctstoptime = '2016-12-08 12:13:26', acctsessiontime = unix_timestamp('2016-12-08 12:13:26') - unix_timestamp(acctstarttime), acctterminatecause = '', acctstopdelay = 0 WHERE acctstoptime IS NULL AND nasipaddress = '192.168.182.1' AND acctstarttime <= '2016-12-08 12:13:26'
Or there may be some mis-configuration as our end. Kindly let me know.
7
11
Hi,
I'm trying EAP-TTLS.Now I'm testing with wpa_supplicant-2.5 for preparation.But I got the following error.This is freeradius-3.0.11(and openssl-1.0.2g).I didn't customize mods-available/eap at all.
Anybody can suggest what could be wrong?
Regards,
/// error in debug by radiusd -XX:Thu Dec 8 00:32:06 2016 : ERROR: (7) eap: Failed continuing EAP MD5 (4) session. EAP sub-module failedThu Dec 8 00:32:06 2016 : Debug: (7) eap: Sending EAP Failure (code 4) ID 1 length 4Thu Dec 8 00:32:06 2016 : Debug: (7) eap: Failed in EAP selectThu Dec 8 00:32:06 2016 : Debug: (7) modsingle[authenticate]: returned from eap (rlm_eap) for request 7Thu Dec 8 00:32:06 2016 : Debug: (7) [eap] = invalidThu Dec 8 00:32:06 2016 : Debug: (7) } # authenticate = invalidThu Dec 8 00:32:06 2016 : Debug: (7) Failed to authenticate the userThu Dec 8 00:32:06 2016 : Auth: (7) Login incorrect (eap: Failed continuing EAP MD5 (4) session. EAP sub-module failed): [eapol_test(a)aikon.jp] (from client localhost port 0 via TLS tunnel)(snip)Thu Dec 8 00:32:07 2016 : Debug: (7) Sent Access-Reject Id 7 from 127.0.0.1:1812 to 127.0.0.1:54818 length 44
/// compiling command:freeradius:./configure --with-openssl --with-openssl-lib-dir=/usr/local/openssl/lib --with-openssl-include-dir=/usr/local/openssl/includeopenssl:./config shared --prefix=/usr/local/openssl
/// config of wpa_supplicant-2.5cat eap-ttls.confnetwork={ eap=TTLS identity="eapol_test(a)aikon.jp" anonymous_identity="anonymous" password="tester" phase2="autheap=MD5"}# https://networkradius.com/doc/FreeRADIUS-Implementation-Ch6.pdf
/// executing command by wpa_supplicant-2.5:./eapol_test -c eap-ttls.conf -s tester -a 127.0.0.1
/// config of "users":cat /usr/local/etc/raddb/userseapol_test(a)aikon.jp Cleartext-Password := "tester"
/// config of "clients.conf"client localhost { ipaddr = 127.0.0.1 proto = * secret = tester require_message_authenticator = no nas_type = other limit { max_connections = 16 lifetime = 0 idle_timeout = 30 }}
/// whole debug:Thu Dec 8 00:32:06 2016 : Debug: (0) Received Access-Request Id 0 from 127.0.0.1:54818 to 127.0.0.1:1812 length 126Thu Dec 8 00:32:06 2016 : Debug: (0) User-Name = "anonymous"Thu Dec 8 00:32:06 2016 : Debug: (0) NAS-IP-Address = 127.0.0.1Thu Dec 8 00:32:06 2016 : Debug: (0) Calling-Station-Id = "02-00-00-00-00-01"Thu Dec 8 00:32:06 2016 : Debug: (0) Framed-MTU = 1400Thu Dec 8 00:32:06 2016 : Debug: (0) NAS-Port-Type = Wireless-802.11Thu Dec 8 00:32:06 2016 : Debug: (0) Connect-Info = "CONNECT 11Mbps 802.11b"Thu Dec 8 00:32:06 2016 : Debug: (0) EAP-Message = 0x0200000e01616e6f6e796d6f7573Thu Dec 8 00:32:06 2016 : Debug: (0) Message-Authenticator = 0x6a5b44af24891d9347e01cbd71cec798Thu Dec 8 00:32:06 2016 : Debug: (0) session-state: No State attributeThu Dec 8 00:32:06 2016 : Debug: (0) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/defaultThu Dec 8 00:32:06 2016 : Debug: (0) authorize {Thu Dec 8 00:32:06 2016 : Debug: (0) policy filter_username {Thu Dec 8 00:32:06 2016 : Debug: (0) if (&User-Name) {Thu Dec 8 00:32:06 2016 : Debug: (0) if (&User-Name) -> TRUEThu Dec 8 00:32:06 2016 : Debug: (0) if (&User-Name) {Thu Dec 8 00:32:06 2016 : Debug: (0) if (&User-Name =~ / /) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (0) if (&User-Name =~ / /) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (0) if (&User-Name =~ /@[^@]*@/ ) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (0) if (&User-Name =~ /@[^@]*@/ ) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (0) if (&User-Name =~ /\.\./ ) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (0) if (&User-Name =~ /\.\./ ) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (0) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (0) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (0) if (&User-Name =~ /\.$/) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (0) if (&User-Name =~ /\.$/) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (0) if (&User-Name =~ /(a)\./) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (0) if (&User-Name =~ /(a)\./) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (0) } # if (&User-Name) = notfoundThu Dec 8 00:32:06 2016 : Debug: (0) } # policy filter_username = notfoundThu Dec 8 00:32:06 2016 : Debug: (0) modsingle[authorize]: calling preprocess (rlm_preprocess) for request 0Thu Dec 8 00:32:06 2016 : Debug: (0) modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 0Thu Dec 8 00:32:06 2016 : Debug: (0) [preprocess] = okThu Dec 8 00:32:06 2016 : Debug: (0) modsingle[authorize]: calling chap (rlm_chap) for request 0Thu Dec 8 00:32:06 2016 : Debug: (0) modsingle[authorize]: returned from chap (rlm_chap) for request 0Thu Dec 8 00:32:06 2016 : Debug: (0) [chap] = noopThu Dec 8 00:32:06 2016 : Debug: (0) modsingle[authorize]: calling mschap (rlm_mschap) for request 0Thu Dec 8 00:32:06 2016 : Debug: (0) modsingle[authorize]: returned from mschap (rlm_mschap) for request 0Thu Dec 8 00:32:06 2016 : Debug: (0) [mschap] = noopThu Dec 8 00:32:06 2016 : Debug: (0) modsingle[authorize]: calling digest (rlm_digest) for request 0Thu Dec 8 00:32:06 2016 : Debug: (0) modsingle[authorize]: returned from digest (rlm_digest) for request 0Thu Dec 8 00:32:06 2016 : Debug: (0) [digest] = noopThu Dec 8 00:32:06 2016 : Debug: (0) modsingle[authorize]: calling suffix (rlm_realm) for request 0Thu Dec 8 00:32:06 2016 : Debug: (0) suffix: Checking for suffix after "@"Thu Dec 8 00:32:06 2016 : Debug: (0) suffix: No '@' in User-Name = "anonymous", looking up realm NULLThu Dec 8 00:32:06 2016 : Debug: (0) suffix: No such realm "NULL"Thu Dec 8 00:32:06 2016 : Debug: (0) modsingle[authorize]: returned from suffix (rlm_realm) for request 0Thu Dec 8 00:32:06 2016 : Debug: (0) [suffix] = noopThu Dec 8 00:32:06 2016 : Debug: (0) modsingle[authorize]: calling eap (rlm_eap) for request 0Thu Dec 8 00:32:06 2016 : Debug: (0) eap: Peer sent EAP Response (code 2) ID 0 length 14Thu Dec 8 00:32:06 2016 : Debug: (0) eap: EAP-Identity reply, returning 'ok' so we can short-circuit the rest of authorizeThu Dec 8 00:32:06 2016 : Debug: (0) modsingle[authorize]: returned from eap (rlm_eap) for request 0Thu Dec 8 00:32:06 2016 : Debug: (0) [eap] = okThu Dec 8 00:32:06 2016 : Debug: (0) } # authorize = okThu Dec 8 00:32:06 2016 : Debug: (0) Found Auth-Type = eapThu Dec 8 00:32:06 2016 : Debug: (0) # Executing group from file /usr/local/etc/raddb/sites-enabled/defaultThu Dec 8 00:32:06 2016 : Debug: (0) authenticate {Thu Dec 8 00:32:06 2016 : Debug: (0) modsingle[authenticate]: calling eap (rlm_eap) for request 0Thu Dec 8 00:32:06 2016 : Debug: (0) eap: Peer sent packet with method EAP Identity (1)Thu Dec 8 00:32:06 2016 : Debug: (0) eap: Calling submodule eap_md5 to process dataThu Dec 8 00:32:06 2016 : Debug: (0) eap_md5: Issuing MD5 ChallengeThu Dec 8 00:32:06 2016 : Debug: (0) eap: Sending EAP Request (code 1) ID 1 length 22Thu Dec 8 00:32:06 2016 : Debug: (0) eap: EAP session adding &reply:State = 0x10c1717110c075fcThu Dec 8 00:32:06 2016 : Debug: (0) modsingle[authenticate]: returned from eap (rlm_eap) for request 0Thu Dec 8 00:32:06 2016 : Debug: (0) [eap] = handledThu Dec 8 00:32:06 2016 : Debug: (0) } # authenticate = handledThu Dec 8 00:32:06 2016 : Debug: (0) Using Post-Auth-Type ChallengeThu Dec 8 00:32:06 2016 : Debug: (0) Post-Auth-Type sub-section not found. Ignoring.Thu Dec 8 00:32:06 2016 : Debug: (0) # Executing group from file /usr/local/etc/raddb/sites-enabled/defaultThu Dec 8 00:32:06 2016 : Debug: (0) session-state: Nothing to cacheThu Dec 8 00:32:06 2016 : Debug: (0) Sent Access-Challenge Id 0 from 127.0.0.1:1812 to 127.0.0.1:54818 length 0Thu Dec 8 00:32:06 2016 : Debug: (0) EAP-Message = 0x010100160410148be0314430ffefaa02aa4393a87209Thu Dec 8 00:32:06 2016 : Debug: (0) Message-Authenticator = 0x00000000000000000000000000000000Thu Dec 8 00:32:06 2016 : Debug: (0) State = 0x10c1717110c075fcf2a6f5bbf92adb57Thu Dec 8 00:32:06 2016 : Debug: (0) Finished requestThu Dec 8 00:32:06 2016 : Debug: Waking up in 4.9 seconds.Thu Dec 8 00:32:06 2016 : Debug: (1) Received Access-Request Id 1 from 127.0.0.1:54818 to 127.0.0.1:1812 length 136Thu Dec 8 00:32:06 2016 : Debug: (1) User-Name = "anonymous"Thu Dec 8 00:32:06 2016 : Debug: (1) NAS-IP-Address = 127.0.0.1Thu Dec 8 00:32:06 2016 : Debug: (1) Calling-Station-Id = "02-00-00-00-00-01"Thu Dec 8 00:32:06 2016 : Debug: (1) Framed-MTU = 1400Thu Dec 8 00:32:06 2016 : Debug: (1) NAS-Port-Type = Wireless-802.11Thu Dec 8 00:32:06 2016 : Debug: (1) Connect-Info = "CONNECT 11Mbps 802.11b"Thu Dec 8 00:32:06 2016 : Debug: (1) EAP-Message = 0x020100060315Thu Dec 8 00:32:06 2016 : Debug: (1) State = 0x10c1717110c075fcf2a6f5bbf92adb57Thu Dec 8 00:32:06 2016 : Debug: (1) Message-Authenticator = 0x931aa8ba75de18053d596ecb4e0fcccdThu Dec 8 00:32:06 2016 : Debug: (1) session-state: No cached attributesThu Dec 8 00:32:06 2016 : Debug: (1) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/defaultThu Dec 8 00:32:06 2016 : Debug: (1) authorize {Thu Dec 8 00:32:06 2016 : Debug: (1) policy filter_username {Thu Dec 8 00:32:06 2016 : Debug: (1) if (&User-Name) {Thu Dec 8 00:32:06 2016 : Debug: (1) if (&User-Name) -> TRUEThu Dec 8 00:32:06 2016 : Debug: (1) if (&User-Name) {Thu Dec 8 00:32:06 2016 : Debug: (1) if (&User-Name =~ / /) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (1) if (&User-Name =~ / /) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (1) if (&User-Name =~ /@[^@]*@/ ) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (1) if (&User-Name =~ /@[^@]*@/ ) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (1) if (&User-Name =~ /\.\./ ) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (1) if (&User-Name =~ /\.\./ ) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (1) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (1) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (1) if (&User-Name =~ /\.$/) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (1) if (&User-Name =~ /\.$/) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (1) if (&User-Name =~ /(a)\./) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (1) if (&User-Name =~ /(a)\./) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (1) } # if (&User-Name) = notfoundThu Dec 8 00:32:06 2016 : Debug: (1) } # policy filter_username = notfoundThu Dec 8 00:32:06 2016 : Debug: (1) modsingle[authorize]: calling preprocess (rlm_preprocess) for request 1Thu Dec 8 00:32:06 2016 : Debug: (1) modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 1Thu Dec 8 00:32:06 2016 : Debug: (1) [preprocess] = okThu Dec 8 00:32:06 2016 : Debug: (1) modsingle[authorize]: calling chap (rlm_chap) for request 1Thu Dec 8 00:32:06 2016 : Debug: (1) modsingle[authorize]: returned from chap (rlm_chap) for request 1Thu Dec 8 00:32:06 2016 : Debug: (1) [chap] = noopThu Dec 8 00:32:06 2016 : Debug: (1) modsingle[authorize]: calling mschap (rlm_mschap) for request 1Thu Dec 8 00:32:06 2016 : Debug: (1) modsingle[authorize]: returned from mschap (rlm_mschap) for request 1Thu Dec 8 00:32:06 2016 : Debug: (1) [mschap] = noopThu Dec 8 00:32:06 2016 : Debug: (1) modsingle[authorize]: calling digest (rlm_digest) for request 1Thu Dec 8 00:32:06 2016 : Debug: (1) modsingle[authorize]: returned from digest (rlm_digest) for request 1Thu Dec 8 00:32:06 2016 : Debug: (1) [digest] = noopThu Dec 8 00:32:06 2016 : Debug: (1) modsingle[authorize]: calling suffix (rlm_realm) for request 1Thu Dec 8 00:32:06 2016 : Debug: (1) suffix: Checking for suffix after "@"Thu Dec 8 00:32:06 2016 : Debug: (1) suffix: No '@' in User-Name = "anonymous", looking up realm NULLThu Dec 8 00:32:06 2016 : Debug: (1) suffix: No such realm "NULL"Thu Dec 8 00:32:06 2016 : Debug: (1) modsingle[authorize]: returned from suffix (rlm_realm) for request 1Thu Dec 8 00:32:06 2016 : Debug: (1) [suffix] = noopThu Dec 8 00:32:06 2016 : Debug: (1) modsingle[authorize]: calling eap (rlm_eap) for request 1Thu Dec 8 00:32:06 2016 : Debug: (1) eap: Peer sent EAP Response (code 2) ID 1 length 6Thu Dec 8 00:32:06 2016 : Debug: (1) eap: No EAP Start, assuming it's an on-going EAP conversationThu Dec 8 00:32:06 2016 : Debug: (1) modsingle[authorize]: returned from eap (rlm_eap) for request 1Thu Dec 8 00:32:06 2016 : Debug: (1) [eap] = updatedThu Dec 8 00:32:06 2016 : Debug: (1) modsingle[authorize]: calling files (rlm_files) for request 1Thu Dec 8 00:32:06 2016 : Debug: (1) modsingle[authorize]: returned from files (rlm_files) for request 1Thu Dec 8 00:32:06 2016 : Debug: (1) [files] = noopThu Dec 8 00:32:06 2016 : Debug: (1) modsingle[authorize]: calling expiration (rlm_expiration) for request 1Thu Dec 8 00:32:06 2016 : Debug: (1) modsingle[authorize]: returned from expiration (rlm_expiration) for request 1Thu Dec 8 00:32:06 2016 : Debug: (1) [expiration] = noopThu Dec 8 00:32:06 2016 : Debug: (1) modsingle[authorize]: calling logintime (rlm_logintime) for request 1Thu Dec 8 00:32:06 2016 : Debug: (1) modsingle[authorize]: returned from logintime (rlm_logintime) for request 1Thu Dec 8 00:32:06 2016 : Debug: (1) [logintime] = noopThu Dec 8 00:32:06 2016 : Debug: (1) modsingle[authorize]: calling pap (rlm_pap) for request 1Thu Dec 8 00:32:06 2016 : WARNING: (1) pap: No "known good" password found for the user. Not setting Auth-TypeThu Dec 8 00:32:06 2016 : WARNING: (1) pap: Authentication will fail unless a "known good" password is availableThu Dec 8 00:32:06 2016 : Debug: (1) modsingle[authorize]: returned from pap (rlm_pap) for request 1Thu Dec 8 00:32:06 2016 : Debug: (1) [pap] = noopThu Dec 8 00:32:06 2016 : Debug: (1) } # authorize = updatedThu Dec 8 00:32:06 2016 : Debug: (1) Found Auth-Type = eapThu Dec 8 00:32:06 2016 : Debug: (1) # Executing group from file /usr/local/etc/raddb/sites-enabled/defaultThu Dec 8 00:32:06 2016 : Debug: (1) authenticate {Thu Dec 8 00:32:06 2016 : Debug: (1) modsingle[authenticate]: calling eap (rlm_eap) for request 1Thu Dec 8 00:32:06 2016 : Debug: (1) eap: Expiring EAP session with state 0x10c1717110c075fcThu Dec 8 00:32:06 2016 : Debug: (1) eap: Finished EAP session with state 0x10c1717110c075fcThu Dec 8 00:32:06 2016 : Debug: (1) eap: Previous EAP request found for state 0x10c1717110c075fc, released from the listThu Dec 8 00:32:06 2016 : Debug: (1) eap: Peer sent packet with method EAP NAK (3)Thu Dec 8 00:32:06 2016 : Debug: (1) eap: Found mutually acceptable type TTLS (21)Thu Dec 8 00:32:06 2016 : Debug: (1) eap: Calling submodule eap_ttls to process dataThu Dec 8 00:32:06 2016 : Debug: (1) eap_ttls: Initiating new EAP-TLS sessionThu Dec 8 00:32:06 2016 : Debug: (1) eap_ttls: Flushing SSL sessions (of #0)Thu Dec 8 00:32:06 2016 : Debug: (1) eap_ttls: [eaptls start] = requestThu Dec 8 00:32:06 2016 : Debug: (1) eap: Sending EAP Request (code 1) ID 2 length 6Thu Dec 8 00:32:06 2016 : Debug: (1) eap: EAP session adding &reply:State = 0x10c1717111c364fcThu Dec 8 00:32:06 2016 : Debug: (1) modsingle[authenticate]: returned from eap (rlm_eap) for request 1Thu Dec 8 00:32:06 2016 : Debug: (1) [eap] = handledThu Dec 8 00:32:06 2016 : Debug: (1) } # authenticate = handledThu Dec 8 00:32:06 2016 : Debug: (1) Using Post-Auth-Type ChallengeThu Dec 8 00:32:06 2016 : Debug: (1) Post-Auth-Type sub-section not found. Ignoring.Thu Dec 8 00:32:06 2016 : Debug: (1) # Executing group from file /usr/local/etc/raddb/sites-enabled/defaultThu Dec 8 00:32:06 2016 : Debug: (1) session-state: Nothing to cacheThu Dec 8 00:32:06 2016 : Debug: (1) Sent Access-Challenge Id 1 from 127.0.0.1:1812 to 127.0.0.1:54818 length 0Thu Dec 8 00:32:06 2016 : Debug: (1) EAP-Message = 0x010200061520Thu Dec 8 00:32:06 2016 : Debug: (1) Message-Authenticator = 0x00000000000000000000000000000000Thu Dec 8 00:32:06 2016 : Debug: (1) State = 0x10c1717111c364fcf2a6f5bbf92adb57Thu Dec 8 00:32:06 2016 : Debug: (1) Finished requestThu Dec 8 00:32:06 2016 : Debug: Waking up in 4.9 seconds.Thu Dec 8 00:32:06 2016 : Debug: (2) Received Access-Request Id 2 from 127.0.0.1:54818 to 127.0.0.1:1812 length 423Thu Dec 8 00:32:06 2016 : Debug: (2) User-Name = "anonymous"Thu Dec 8 00:32:06 2016 : Debug: (2) NAS-IP-Address = 127.0.0.1Thu Dec 8 00:32:06 2016 : Debug: (2) Calling-Station-Id = "02-00-00-00-00-01"Thu Dec 8 00:32:06 2016 : Debug: (2) Framed-MTU = 1400Thu Dec 8 00:32:06 2016 : Debug: (2) NAS-Port-Type = Wireless-802.11Thu Dec 8 00:32:06 2016 : Debug: (2) Connect-Info = "CONNECT 11Mbps 802.11b"Thu Dec 8 00:32:06 2016 : Debug: (2) EAP-Message = 0x0202012315001603010118010001140303cae0610d1e6b8100c007621e34def0ebe6cf945950b45515aba196cc342a1288000082c030c02cc028c024c014c00a00a3009f006b006a0039003800880087c032c02ec02ac026c00fc005009d003d00350084c012c00800160013c00dc003000ac02fc02bc0Thu Dec 8 00:32:06 2016 : Debug: (2) State = 0x10c1717111c364fcf2a6f5bbf92adb57Thu Dec 8 00:32:06 2016 : Debug: (2) Message-Authenticator = 0x910cc0b973e5dbf44407b7281379ebf2Thu Dec 8 00:32:06 2016 : Debug: (2) session-state: No cached attributesThu Dec 8 00:32:06 2016 : Debug: (2) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/defaultThu Dec 8 00:32:06 2016 : Debug: (2) authorize {Thu Dec 8 00:32:06 2016 : Debug: (2) policy filter_username {Thu Dec 8 00:32:06 2016 : Debug: (2) if (&User-Name) {Thu Dec 8 00:32:06 2016 : Debug: (2) if (&User-Name) -> TRUEThu Dec 8 00:32:06 2016 : Debug: (2) if (&User-Name) {Thu Dec 8 00:32:06 2016 : Debug: (2) if (&User-Name =~ / /) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (2) if (&User-Name =~ / /) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (2) if (&User-Name =~ /@[^@]*@/ ) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (2) if (&User-Name =~ /@[^@]*@/ ) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (2) if (&User-Name =~ /\.\./ ) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (2) if (&User-Name =~ /\.\./ ) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (2) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (2) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (2) if (&User-Name =~ /\.$/) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (2) if (&User-Name =~ /\.$/) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (2) if (&User-Name =~ /(a)\./) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (2) if (&User-Name =~ /(a)\./) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (2) } # if (&User-Name) = notfoundThu Dec 8 00:32:06 2016 : Debug: (2) } # policy filter_username = notfoundThu Dec 8 00:32:06 2016 : Debug: (2) modsingle[authorize]: calling preprocess (rlm_preprocess) for request 2Thu Dec 8 00:32:06 2016 : Debug: (2) modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 2Thu Dec 8 00:32:06 2016 : Debug: (2) [preprocess] = okThu Dec 8 00:32:06 2016 : Debug: (2) modsingle[authorize]: calling chap (rlm_chap) for request 2Thu Dec 8 00:32:06 2016 : Debug: (2) modsingle[authorize]: returned from chap (rlm_chap) for request 2Thu Dec 8 00:32:06 2016 : Debug: (2) [chap] = noopThu Dec 8 00:32:06 2016 : Debug: (2) modsingle[authorize]: calling mschap (rlm_mschap) for request 2Thu Dec 8 00:32:06 2016 : Debug: (2) modsingle[authorize]: returned from mschap (rlm_mschap) for request 2Thu Dec 8 00:32:06 2016 : Debug: (2) [mschap] = noopThu Dec 8 00:32:06 2016 : Debug: (2) modsingle[authorize]: calling digest (rlm_digest) for request 2Thu Dec 8 00:32:06 2016 : Debug: (2) modsingle[authorize]: returned from digest (rlm_digest) for request 2Thu Dec 8 00:32:06 2016 : Debug: (2) [digest] = noopThu Dec 8 00:32:06 2016 : Debug: (2) modsingle[authorize]: calling suffix (rlm_realm) for request 2Thu Dec 8 00:32:06 2016 : Debug: (2) suffix: Checking for suffix after "@"Thu Dec 8 00:32:06 2016 : Debug: (2) suffix: No '@' in User-Name = "anonymous", looking up realm NULLThu Dec 8 00:32:06 2016 : Debug: (2) suffix: No such realm "NULL"Thu Dec 8 00:32:06 2016 : Debug: (2) modsingle[authorize]: returned from suffix (rlm_realm) for request 2Thu Dec 8 00:32:06 2016 : Debug: (2) [suffix] = noopThu Dec 8 00:32:06 2016 : Debug: (2) modsingle[authorize]: calling eap (rlm_eap) for request 2Thu Dec 8 00:32:06 2016 : Debug: (2) eap: Peer sent EAP Response (code 2) ID 2 length 291Thu Dec 8 00:32:06 2016 : Debug: (2) eap: Continuing tunnel setupThu Dec 8 00:32:06 2016 : Debug: (2) modsingle[authorize]: returned from eap (rlm_eap) for request 2Thu Dec 8 00:32:06 2016 : Debug: (2) [eap] = okThu Dec 8 00:32:06 2016 : Debug: (2) } # authorize = okThu Dec 8 00:32:06 2016 : Debug: (2) Found Auth-Type = eapThu Dec 8 00:32:06 2016 : Debug: (2) # Executing group from file /usr/local/etc/raddb/sites-enabled/defaultThu Dec 8 00:32:06 2016 : Debug: (2) authenticate {Thu Dec 8 00:32:06 2016 : Debug: (2) modsingle[authenticate]: calling eap (rlm_eap) for request 2Thu Dec 8 00:32:06 2016 : Debug: (2) eap: Expiring EAP session with state 0x10c1717111c364fcThu Dec 8 00:32:06 2016 : Debug: (2) eap: Finished EAP session with state 0x10c1717111c364fcThu Dec 8 00:32:06 2016 : Debug: (2) eap: Previous EAP request found for state 0x10c1717111c364fc, released from the listThu Dec 8 00:32:06 2016 : Debug: (2) eap: Peer sent packet with method EAP TTLS (21)Thu Dec 8 00:32:06 2016 : Debug: (2) eap: Calling submodule eap_ttls to process dataThu Dec 8 00:32:06 2016 : Debug: (2) eap_ttls: AuthenticateThu Dec 8 00:32:06 2016 : Debug: (2) eap_ttls: Continuing EAP-TLSThu Dec 8 00:32:06 2016 : Debug: (2) eap_ttls: Peer sent flags ---Thu Dec 8 00:32:06 2016 : Debug: (2) eap_ttls: [eaptls verify] = okThu Dec 8 00:32:06 2016 : Debug: (2) eap_ttls: Done initial handshakeThu Dec 8 00:32:06 2016 : Debug: (2) eap_ttls: (other): before/accept initializationThu Dec 8 00:32:06 2016 : Debug: (2) eap_ttls: TLS_accept: before/accept initializationThu Dec 8 00:32:06 2016 : Debug: Ignoring cbtls_msg call with pseudo content type 256, version 0Thu Dec 8 00:32:06 2016 : Debug: (2) eap_ttls: <<< recv TLS 1.2 [length 0118]Thu Dec 8 00:32:06 2016 : Debug: (2) eap_ttls: TLS_accept: SSLv3 read client hello AThu Dec 8 00:32:06 2016 : Debug: Ignoring cbtls_msg call with pseudo content type 256, version 0Thu Dec 8 00:32:06 2016 : Debug: (2) eap_ttls: >>> send TLS 1.2 [length 005e]Thu Dec 8 00:32:06 2016 : Debug: (2) eap_ttls: TLS_accept: SSLv3 write server hello AThu Dec 8 00:32:06 2016 : Debug: Ignoring cbtls_msg call with pseudo content type 256, version 0Thu Dec 8 00:32:06 2016 : Debug: (2) eap_ttls: >>> send TLS 1.2 [length 0813]Thu Dec 8 00:32:06 2016 : Debug: (2) eap_ttls: TLS_accept: SSLv3 write certificate AThu Dec 8 00:32:06 2016 : Debug: Ignoring cbtls_msg call with pseudo content type 256, version 0Thu Dec 8 00:32:06 2016 : Debug: (2) eap_ttls: >>> send TLS 1.2 [length 014d]Thu Dec 8 00:32:06 2016 : Debug: (2) eap_ttls: TLS_accept: SSLv3 write key exchange AThu Dec 8 00:32:06 2016 : Debug: Ignoring cbtls_msg call with pseudo content type 256, version 0Thu Dec 8 00:32:06 2016 : Debug: (2) eap_ttls: >>> send TLS 1.2 [length 0004]Thu Dec 8 00:32:06 2016 : Debug: (2) eap_ttls: TLS_accept: SSLv3 write server done AThu Dec 8 00:32:06 2016 : Debug: (2) eap_ttls: TLS_accept: SSLv3 flush dataThu Dec 8 00:32:06 2016 : Debug: (2) eap_ttls: TLS_accept: SSLv3 read client certificate AThu Dec 8 00:32:06 2016 : Debug: (2) eap_ttls: TLS_accept: Need to read more data: SSLv3 read client key exchange AThu Dec 8 00:32:06 2016 : Debug: (2) eap_ttls: TLS_accept: Need to read more data: SSLv3 read client key exchange AThu Dec 8 00:32:06 2016 : Debug: (2) eap_ttls: In SSL Handshake PhaseThu Dec 8 00:32:06 2016 : Debug: (2) eap_ttls: In SSL Accept modeThu Dec 8 00:32:06 2016 : Debug: (2) eap_ttls: [eaptls process] = handledThu Dec 8 00:32:06 2016 : Debug: (2) eap: Sending EAP Request (code 1) ID 3 length 1004Thu Dec 8 00:32:06 2016 : Debug: (2) eap: EAP session adding &reply:State = 0x10c1717112c264fcThu Dec 8 00:32:06 2016 : Debug: (2) modsingle[authenticate]: returned from eap (rlm_eap) for request 2Thu Dec 8 00:32:06 2016 : Debug: (2) [eap] = handledThu Dec 8 00:32:06 2016 : Debug: (2) } # authenticate = handledThu Dec 8 00:32:06 2016 : Debug: (2) Using Post-Auth-Type ChallengeThu Dec 8 00:32:06 2016 : Debug: (2) Post-Auth-Type sub-section not found. Ignoring.Thu Dec 8 00:32:06 2016 : Debug: (2) # Executing group from file /usr/local/etc/raddb/sites-enabled/defaultThu Dec 8 00:32:06 2016 : Debug: (2) session-state: Nothing to cacheThu Dec 8 00:32:06 2016 : Debug: (2) Sent Access-Challenge Id 2 from 127.0.0.1:1812 to 127.0.0.1:54818 length 0Thu Dec 8 00:32:06 2016 : Debug: (2) EAP-Message = 0x010303ec15c0000009d6160303005e0200005a03039e4ca71cf04c8e662d2936617c41d9f3a5b54ea05741888a6f933888fec2110d203344cf5126fb4cf727a39331e315f534a64dde1d6d8c12c35b10a710ec96d857c030000012ff01000100000b000403000102000f00010116030308130b00080f00Thu Dec 8 00:32:06 2016 : Debug: (2) Message-Authenticator = 0x00000000000000000000000000000000Thu Dec 8 00:32:06 2016 : Debug: (2) State = 0x10c1717112c264fcf2a6f5bbf92adb57Thu Dec 8 00:32:06 2016 : Debug: (2) Finished requestThu Dec 8 00:32:06 2016 : Debug: Waking up in 4.9 seconds.Thu Dec 8 00:32:06 2016 : Debug: (3) Received Access-Request Id 3 from 127.0.0.1:54818 to 127.0.0.1:1812 length 136Thu Dec 8 00:32:06 2016 : Debug: (3) User-Name = "anonymous"Thu Dec 8 00:32:06 2016 : Debug: (3) NAS-IP-Address = 127.0.0.1Thu Dec 8 00:32:06 2016 : Debug: (3) Calling-Station-Id = "02-00-00-00-00-01"Thu Dec 8 00:32:06 2016 : Debug: (3) Framed-MTU = 1400Thu Dec 8 00:32:06 2016 : Debug: (3) NAS-Port-Type = Wireless-802.11Thu Dec 8 00:32:06 2016 : Debug: (3) Connect-Info = "CONNECT 11Mbps 802.11b"Thu Dec 8 00:32:06 2016 : Debug: (3) EAP-Message = 0x020300061500Thu Dec 8 00:32:06 2016 : Debug: (3) State = 0x10c1717112c264fcf2a6f5bbf92adb57Thu Dec 8 00:32:06 2016 : Debug: (3) Message-Authenticator = 0x9f42a30edc80a507954951c07a942441Thu Dec 8 00:32:06 2016 : Debug: (3) session-state: No cached attributesThu Dec 8 00:32:06 2016 : Debug: (3) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/defaultThu Dec 8 00:32:06 2016 : Debug: (3) authorize {Thu Dec 8 00:32:06 2016 : Debug: (3) policy filter_username {Thu Dec 8 00:32:06 2016 : Debug: (3) if (&User-Name) {Thu Dec 8 00:32:06 2016 : Debug: (3) if (&User-Name) -> TRUEThu Dec 8 00:32:06 2016 : Debug: (3) if (&User-Name) {Thu Dec 8 00:32:06 2016 : Debug: (3) if (&User-Name =~ / /) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (3) if (&User-Name =~ / /) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (3) if (&User-Name =~ /@[^@]*@/ ) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (3) if (&User-Name =~ /@[^@]*@/ ) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (3) if (&User-Name =~ /\.\./ ) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (3) if (&User-Name =~ /\.\./ ) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (3) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (3) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (3) if (&User-Name =~ /\.$/) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (3) if (&User-Name =~ /\.$/) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (3) if (&User-Name =~ /(a)\./) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (3) if (&User-Name =~ /(a)\./) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (3) } # if (&User-Name) = notfoundThu Dec 8 00:32:06 2016 : Debug: (3) } # policy filter_username = notfoundThu Dec 8 00:32:06 2016 : Debug: (3) modsingle[authorize]: calling preprocess (rlm_preprocess) for request 3Thu Dec 8 00:32:06 2016 : Debug: (3) modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 3Thu Dec 8 00:32:06 2016 : Debug: (3) [preprocess] = okThu Dec 8 00:32:06 2016 : Debug: (3) modsingle[authorize]: calling chap (rlm_chap) for request 3Thu Dec 8 00:32:06 2016 : Debug: (3) modsingle[authorize]: returned from chap (rlm_chap) for request 3Thu Dec 8 00:32:06 2016 : Debug: (3) [chap] = noopThu Dec 8 00:32:06 2016 : Debug: (3) modsingle[authorize]: calling mschap (rlm_mschap) for request 3Thu Dec 8 00:32:06 2016 : Debug: (3) modsingle[authorize]: returned from mschap (rlm_mschap) for request 3Thu Dec 8 00:32:06 2016 : Debug: (3) [mschap] = noopThu Dec 8 00:32:06 2016 : Debug: (3) modsingle[authorize]: calling digest (rlm_digest) for request 3Thu Dec 8 00:32:06 2016 : Debug: (3) modsingle[authorize]: returned from digest (rlm_digest) for request 3Thu Dec 8 00:32:06 2016 : Debug: (3) [digest] = noopThu Dec 8 00:32:06 2016 : Debug: (3) modsingle[authorize]: calling suffix (rlm_realm) for request 3Thu Dec 8 00:32:06 2016 : Debug: (3) suffix: Checking for suffix after "@"Thu Dec 8 00:32:06 2016 : Debug: (3) suffix: No '@' in User-Name = "anonymous", looking up realm NULLThu Dec 8 00:32:06 2016 : Debug: (3) suffix: No such realm "NULL"Thu Dec 8 00:32:06 2016 : Debug: (3) modsingle[authorize]: returned from suffix (rlm_realm) for request 3Thu Dec 8 00:32:06 2016 : Debug: (3) [suffix] = noopThu Dec 8 00:32:06 2016 : Debug: (3) modsingle[authorize]: calling eap (rlm_eap) for request 3Thu Dec 8 00:32:06 2016 : Debug: (3) eap: Peer sent EAP Response (code 2) ID 3 length 6Thu Dec 8 00:32:06 2016 : Debug: (3) eap: Continuing tunnel setupThu Dec 8 00:32:06 2016 : Debug: (3) modsingle[authorize]: returned from eap (rlm_eap) for request 3Thu Dec 8 00:32:06 2016 : Debug: (3) [eap] = okThu Dec 8 00:32:06 2016 : Debug: (3) } # authorize = okThu Dec 8 00:32:06 2016 : Debug: (3) Found Auth-Type = eapThu Dec 8 00:32:06 2016 : Debug: (3) # Executing group from file /usr/local/etc/raddb/sites-enabled/defaultThu Dec 8 00:32:06 2016 : Debug: (3) authenticate {Thu Dec 8 00:32:06 2016 : Debug: (3) modsingle[authenticate]: calling eap (rlm_eap) for request 3Thu Dec 8 00:32:06 2016 : Debug: (3) eap: Expiring EAP session with state 0x10c1717112c264fcThu Dec 8 00:32:06 2016 : Debug: (3) eap: Finished EAP session with state 0x10c1717112c264fcThu Dec 8 00:32:06 2016 : Debug: (3) eap: Previous EAP request found for state 0x10c1717112c264fc, released from the listThu Dec 8 00:32:06 2016 : Debug: (3) eap: Peer sent packet with method EAP TTLS (21)Thu Dec 8 00:32:06 2016 : Debug: (3) eap: Calling submodule eap_ttls to process dataThu Dec 8 00:32:06 2016 : Debug: (3) eap_ttls: AuthenticateThu Dec 8 00:32:06 2016 : Debug: (3) eap_ttls: Continuing EAP-TLSThu Dec 8 00:32:06 2016 : Debug: (3) eap_ttls: Peer sent flags ---Thu Dec 8 00:32:06 2016 : Debug: (3) eap_ttls: Peer ACKed our handshake fragmentThu Dec 8 00:32:06 2016 : Debug: (3) eap_ttls: [eaptls verify] = requestThu Dec 8 00:32:06 2016 : Debug: (3) eap_ttls: [eaptls process] = handledThu Dec 8 00:32:06 2016 : Debug: (3) eap: Sending EAP Request (code 1) ID 4 length 1004Thu Dec 8 00:32:06 2016 : Debug: (3) eap: EAP session adding &reply:State = 0x10c1717113c564fcThu Dec 8 00:32:06 2016 : Debug: (3) modsingle[authenticate]: returned from eap (rlm_eap) for request 3Thu Dec 8 00:32:06 2016 : Debug: (3) [eap] = handledThu Dec 8 00:32:06 2016 : Debug: (3) } # authenticate = handledThu Dec 8 00:32:06 2016 : Debug: (3) Using Post-Auth-Type ChallengeThu Dec 8 00:32:06 2016 : Debug: (3) Post-Auth-Type sub-section not found. Ignoring.Thu Dec 8 00:32:06 2016 : Debug: (3) # Executing group from file /usr/local/etc/raddb/sites-enabled/defaultThu Dec 8 00:32:06 2016 : Debug: (3) session-state: Nothing to cacheThu Dec 8 00:32:06 2016 : Debug: (3) Sent Access-Challenge Id 3 from 127.0.0.1:1812 to 127.0.0.1:54818 length 0Thu Dec 8 00:32:06 2016 : Debug: (3) EAP-Message = 0x010403ec15c0000009d6add6d7bffc0f82cf52e869ceddc3a2612a034c6143e26901836d38631698ce516bd8bf8bc1a41f19bc403054b7ae6a0ff6bcd57233f0d9771c3123bfc18ca1c19f8b9d2eb9b44e27397129f22af1f806ec15491dbddd9505ff28bda45dfcfb77430f3abad91cc809df05032072Thu Dec 8 00:32:06 2016 : Debug: (3) Message-Authenticator = 0x00000000000000000000000000000000Thu Dec 8 00:32:06 2016 : Debug: (3) State = 0x10c1717113c564fcf2a6f5bbf92adb57Thu Dec 8 00:32:06 2016 : Debug: (3) Finished requestThu Dec 8 00:32:06 2016 : Debug: Waking up in 4.9 seconds.Thu Dec 8 00:32:06 2016 : Debug: (4) Received Access-Request Id 4 from 127.0.0.1:54818 to 127.0.0.1:1812 length 136Thu Dec 8 00:32:06 2016 : Debug: (4) User-Name = "anonymous"Thu Dec 8 00:32:06 2016 : Debug: (4) NAS-IP-Address = 127.0.0.1Thu Dec 8 00:32:06 2016 : Debug: (4) Calling-Station-Id = "02-00-00-00-00-01"Thu Dec 8 00:32:06 2016 : Debug: (4) Framed-MTU = 1400Thu Dec 8 00:32:06 2016 : Debug: (4) NAS-Port-Type = Wireless-802.11Thu Dec 8 00:32:06 2016 : Debug: (4) Connect-Info = "CONNECT 11Mbps 802.11b"Thu Dec 8 00:32:06 2016 : Debug: (4) EAP-Message = 0x020400061500Thu Dec 8 00:32:06 2016 : Debug: (4) State = 0x10c1717113c564fcf2a6f5bbf92adb57Thu Dec 8 00:32:06 2016 : Debug: (4) Message-Authenticator = 0x54d84b9e194fc9f2e4f34e2c0e1a757eThu Dec 8 00:32:06 2016 : Debug: (4) session-state: No cached attributesThu Dec 8 00:32:06 2016 : Debug: (4) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/defaultThu Dec 8 00:32:06 2016 : Debug: (4) authorize {Thu Dec 8 00:32:06 2016 : Debug: (4) policy filter_username {Thu Dec 8 00:32:06 2016 : Debug: (4) if (&User-Name) {Thu Dec 8 00:32:06 2016 : Debug: (4) if (&User-Name) -> TRUEThu Dec 8 00:32:06 2016 : Debug: (4) if (&User-Name) {Thu Dec 8 00:32:06 2016 : Debug: (4) if (&User-Name =~ / /) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (4) if (&User-Name =~ / /) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (4) if (&User-Name =~ /@[^@]*@/ ) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (4) if (&User-Name =~ /@[^@]*@/ ) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (4) if (&User-Name =~ /\.\./ ) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (4) if (&User-Name =~ /\.\./ ) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (4) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (4) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (4) if (&User-Name =~ /\.$/) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (4) if (&User-Name =~ /\.$/) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (4) if (&User-Name =~ /(a)\./) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (4) if (&User-Name =~ /(a)\./) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (4) } # if (&User-Name) = notfoundThu Dec 8 00:32:06 2016 : Debug: (4) } # policy filter_username = notfoundThu Dec 8 00:32:06 2016 : Debug: (4) modsingle[authorize]: calling preprocess (rlm_preprocess) for request 4Thu Dec 8 00:32:06 2016 : Debug: (4) modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 4Thu Dec 8 00:32:06 2016 : Debug: (4) [preprocess] = okThu Dec 8 00:32:06 2016 : Debug: (4) modsingle[authorize]: calling chap (rlm_chap) for request 4Thu Dec 8 00:32:06 2016 : Debug: (4) modsingle[authorize]: returned from chap (rlm_chap) for request 4Thu Dec 8 00:32:06 2016 : Debug: (4) [chap] = noopThu Dec 8 00:32:06 2016 : Debug: (4) modsingle[authorize]: calling mschap (rlm_mschap) for request 4Thu Dec 8 00:32:06 2016 : Debug: (4) modsingle[authorize]: returned from mschap (rlm_mschap) for request 4Thu Dec 8 00:32:06 2016 : Debug: (4) [mschap] = noopThu Dec 8 00:32:06 2016 : Debug: (4) modsingle[authorize]: calling digest (rlm_digest) for request 4Thu Dec 8 00:32:06 2016 : Debug: (4) modsingle[authorize]: returned from digest (rlm_digest) for request 4Thu Dec 8 00:32:06 2016 : Debug: (4) [digest] = noopThu Dec 8 00:32:06 2016 : Debug: (4) modsingle[authorize]: calling suffix (rlm_realm) for request 4Thu Dec 8 00:32:06 2016 : Debug: (4) suffix: Checking for suffix after "@"Thu Dec 8 00:32:06 2016 : Debug: (4) suffix: No '@' in User-Name = "anonymous", looking up realm NULLThu Dec 8 00:32:06 2016 : Debug: (4) suffix: No such realm "NULL"Thu Dec 8 00:32:06 2016 : Debug: (4) modsingle[authorize]: returned from suffix (rlm_realm) for request 4Thu Dec 8 00:32:06 2016 : Debug: (4) [suffix] = noopThu Dec 8 00:32:06 2016 : Debug: (4) modsingle[authorize]: calling eap (rlm_eap) for request 4Thu Dec 8 00:32:06 2016 : Debug: (4) eap: Peer sent EAP Response (code 2) ID 4 length 6Thu Dec 8 00:32:06 2016 : Debug: (4) eap: Continuing tunnel setupThu Dec 8 00:32:06 2016 : Debug: (4) modsingle[authorize]: returned from eap (rlm_eap) for request 4Thu Dec 8 00:32:06 2016 : Debug: (4) [eap] = okThu Dec 8 00:32:06 2016 : Debug: (4) } # authorize = okThu Dec 8 00:32:06 2016 : Debug: (4) Found Auth-Type = eapThu Dec 8 00:32:06 2016 : Debug: (4) # Executing group from file /usr/local/etc/raddb/sites-enabled/defaultThu Dec 8 00:32:06 2016 : Debug: (4) authenticate {Thu Dec 8 00:32:06 2016 : Debug: (4) modsingle[authenticate]: calling eap (rlm_eap) for request 4Thu Dec 8 00:32:06 2016 : Debug: (4) eap: Expiring EAP session with state 0x10c1717113c564fcThu Dec 8 00:32:06 2016 : Debug: (4) eap: Finished EAP session with state 0x10c1717113c564fcThu Dec 8 00:32:06 2016 : Debug: (4) eap: Previous EAP request found for state 0x10c1717113c564fc, released from the listThu Dec 8 00:32:06 2016 : Debug: (4) eap: Peer sent packet with method EAP TTLS (21)Thu Dec 8 00:32:06 2016 : Debug: (4) eap: Calling submodule eap_ttls to process dataThu Dec 8 00:32:06 2016 : Debug: (4) eap_ttls: AuthenticateThu Dec 8 00:32:06 2016 : Debug: (4) eap_ttls: Continuing EAP-TLSThu Dec 8 00:32:06 2016 : Debug: (4) eap_ttls: Peer sent flags ---Thu Dec 8 00:32:06 2016 : Debug: (4) eap_ttls: Peer ACKed our handshake fragmentThu Dec 8 00:32:06 2016 : Debug: (4) eap_ttls: [eaptls verify] = requestThu Dec 8 00:32:06 2016 : Debug: (4) eap_ttls: [eaptls process] = handledThu Dec 8 00:32:06 2016 : Debug: (4) eap: Sending EAP Request (code 1) ID 5 length 540Thu Dec 8 00:32:06 2016 : Debug: (4) eap: EAP session adding &reply:State = 0x10c1717114c464fcThu Dec 8 00:32:06 2016 : Debug: (4) modsingle[authenticate]: returned from eap (rlm_eap) for request 4Thu Dec 8 00:32:06 2016 : Debug: (4) [eap] = handledThu Dec 8 00:32:06 2016 : Debug: (4) } # authenticate = handledThu Dec 8 00:32:06 2016 : Debug: (4) Using Post-Auth-Type ChallengeThu Dec 8 00:32:06 2016 : Debug: (4) Post-Auth-Type sub-section not found. Ignoring.Thu Dec 8 00:32:06 2016 : Debug: (4) # Executing group from file /usr/local/etc/raddb/sites-enabled/defaultThu Dec 8 00:32:06 2016 : Debug: (4) session-state: Nothing to cacheThu Dec 8 00:32:06 2016 : Debug: (4) Sent Access-Challenge Id 4 from 127.0.0.1:1812 to 127.0.0.1:54818 length 0Thu Dec 8 00:32:06 2016 : Debug: (4) EAP-Message = 0x0105021c1580000009d6cf3138ddf0922ae5628ffcfed6f592c1d5cca8d32af57f60de724642996952991b8d6f0078f6b530bb3b269c6735e97bb69f59773a5eed5d161a61b433cbfc8264257c2211af3bb752f857422cd4b639c6949edf2cfcdbf6842b7486ae2e5eb3af34e54a0de2ad5167953b036eThu Dec 8 00:32:06 2016 : Debug: (4) Message-Authenticator = 0x00000000000000000000000000000000Thu Dec 8 00:32:06 2016 : Debug: (4) State = 0x10c1717114c464fcf2a6f5bbf92adb57Thu Dec 8 00:32:06 2016 : Debug: (4) Finished requestThu Dec 8 00:32:06 2016 : Debug: Waking up in 4.9 seconds.Thu Dec 8 00:32:06 2016 : Debug: (5) Received Access-Request Id 5 from 127.0.0.1:54818 to 127.0.0.1:1812 length 262Thu Dec 8 00:32:06 2016 : Debug: (5) User-Name = "anonymous"Thu Dec 8 00:32:06 2016 : Debug: (5) NAS-IP-Address = 127.0.0.1Thu Dec 8 00:32:06 2016 : Debug: (5) Calling-Station-Id = "02-00-00-00-00-01"Thu Dec 8 00:32:06 2016 : Debug: (5) Framed-MTU = 1400Thu Dec 8 00:32:06 2016 : Debug: (5) NAS-Port-Type = Wireless-802.11Thu Dec 8 00:32:06 2016 : Debug: (5) Connect-Info = "CONNECT 11Mbps 802.11b"Thu Dec 8 00:32:06 2016 : Debug: (5) EAP-Message = 0x020500841500160303004610000042410463a7f35b4f786657607e68c82ab4c2c506d9b924d1a9d7f7ac206bece71d89b09ef287573206209a61e433957cec614a0ea4a9fbd1f74d408c090a9e9a681a0a14030300010116030300282551dc6df862b4c0b9b3d9966d271166a153c14d3a16888963f35fThu Dec 8 00:32:06 2016 : Debug: (5) State = 0x10c1717114c464fcf2a6f5bbf92adb57Thu Dec 8 00:32:06 2016 : Debug: (5) Message-Authenticator = 0x85f0021449b941960ec494ca1f4dfd33Thu Dec 8 00:32:06 2016 : Debug: (5) session-state: No cached attributesThu Dec 8 00:32:06 2016 : Debug: (5) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/defaultThu Dec 8 00:32:06 2016 : Debug: (5) authorize {Thu Dec 8 00:32:06 2016 : Debug: (5) policy filter_username {Thu Dec 8 00:32:06 2016 : Debug: (5) if (&User-Name) {Thu Dec 8 00:32:06 2016 : Debug: (5) if (&User-Name) -> TRUEThu Dec 8 00:32:06 2016 : Debug: (5) if (&User-Name) {Thu Dec 8 00:32:06 2016 : Debug: (5) if (&User-Name =~ / /) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (5) if (&User-Name =~ / /) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (5) if (&User-Name =~ /@[^@]*@/ ) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (5) if (&User-Name =~ /@[^@]*@/ ) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (5) if (&User-Name =~ /\.\./ ) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (5) if (&User-Name =~ /\.\./ ) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (5) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (5) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (5) if (&User-Name =~ /\.$/) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (5) if (&User-Name =~ /\.$/) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (5) if (&User-Name =~ /(a)\./) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (5) if (&User-Name =~ /(a)\./) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (5) } # if (&User-Name) = notfoundThu Dec 8 00:32:06 2016 : Debug: (5) } # policy filter_username = notfoundThu Dec 8 00:32:06 2016 : Debug: (5) modsingle[authorize]: calling preprocess (rlm_preprocess) for request 5Thu Dec 8 00:32:06 2016 : Debug: (5) modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 5Thu Dec 8 00:32:06 2016 : Debug: (5) [preprocess] = okThu Dec 8 00:32:06 2016 : Debug: (5) modsingle[authorize]: calling chap (rlm_chap) for request 5Thu Dec 8 00:32:06 2016 : Debug: (5) modsingle[authorize]: returned from chap (rlm_chap) for request 5Thu Dec 8 00:32:06 2016 : Debug: (5) [chap] = noopThu Dec 8 00:32:06 2016 : Debug: (5) modsingle[authorize]: calling mschap (rlm_mschap) for request 5Thu Dec 8 00:32:06 2016 : Debug: (5) modsingle[authorize]: returned from mschap (rlm_mschap) for request 5Thu Dec 8 00:32:06 2016 : Debug: (5) [mschap] = noopThu Dec 8 00:32:06 2016 : Debug: (5) modsingle[authorize]: calling digest (rlm_digest) for request 5Thu Dec 8 00:32:06 2016 : Debug: (5) modsingle[authorize]: returned from digest (rlm_digest) for request 5Thu Dec 8 00:32:06 2016 : Debug: (5) [digest] = noopThu Dec 8 00:32:06 2016 : Debug: (5) modsingle[authorize]: calling suffix (rlm_realm) for request 5Thu Dec 8 00:32:06 2016 : Debug: (5) suffix: Checking for suffix after "@"Thu Dec 8 00:32:06 2016 : Debug: (5) suffix: No '@' in User-Name = "anonymous", looking up realm NULLThu Dec 8 00:32:06 2016 : Debug: (5) suffix: No such realm "NULL"Thu Dec 8 00:32:06 2016 : Debug: (5) modsingle[authorize]: returned from suffix (rlm_realm) for request 5Thu Dec 8 00:32:06 2016 : Debug: (5) [suffix] = noopThu Dec 8 00:32:06 2016 : Debug: (5) modsingle[authorize]: calling eap (rlm_eap) for request 5Thu Dec 8 00:32:06 2016 : Debug: (5) eap: Peer sent EAP Response (code 2) ID 5 length 132Thu Dec 8 00:32:06 2016 : Debug: (5) eap: Continuing tunnel setupThu Dec 8 00:32:06 2016 : Debug: (5) modsingle[authorize]: returned from eap (rlm_eap) for request 5Thu Dec 8 00:32:06 2016 : Debug: (5) [eap] = okThu Dec 8 00:32:06 2016 : Debug: (5) } # authorize = okThu Dec 8 00:32:06 2016 : Debug: (5) Found Auth-Type = eapThu Dec 8 00:32:06 2016 : Debug: (5) # Executing group from file /usr/local/etc/raddb/sites-enabled/defaultThu Dec 8 00:32:06 2016 : Debug: (5) authenticate {Thu Dec 8 00:32:06 2016 : Debug: (5) modsingle[authenticate]: calling eap (rlm_eap) for request 5Thu Dec 8 00:32:06 2016 : Debug: (5) eap: Expiring EAP session with state 0x10c1717114c464fcThu Dec 8 00:32:06 2016 : Debug: (5) eap: Finished EAP session with state 0x10c1717114c464fcThu Dec 8 00:32:06 2016 : Debug: (5) eap: Previous EAP request found for state 0x10c1717114c464fc, released from the listThu Dec 8 00:32:06 2016 : Debug: (5) eap: Peer sent packet with method EAP TTLS (21)Thu Dec 8 00:32:06 2016 : Debug: (5) eap: Calling submodule eap_ttls to process dataThu Dec 8 00:32:06 2016 : Debug: (5) eap_ttls: AuthenticateThu Dec 8 00:32:06 2016 : Debug: (5) eap_ttls: Continuing EAP-TLSThu Dec 8 00:32:06 2016 : Debug: (5) eap_ttls: Peer sent flags ---Thu Dec 8 00:32:06 2016 : Debug: (5) eap_ttls: [eaptls verify] = okThu Dec 8 00:32:06 2016 : Debug: (5) eap_ttls: Done initial handshakeThu Dec 8 00:32:06 2016 : Debug: Ignoring cbtls_msg call with pseudo content type 256, version 0Thu Dec 8 00:32:06 2016 : Debug: (5) eap_ttls: <<< recv TLS 1.2 [length 0046]Thu Dec 8 00:32:06 2016 : Debug: (5) eap_ttls: TLS_accept: SSLv3 read client key exchange AThu Dec 8 00:32:06 2016 : Debug: (5) eap_ttls: TLS_accept: SSLv3 read certificate verify AThu Dec 8 00:32:06 2016 : Debug: Ignoring cbtls_msg call with pseudo content type 256, version 0Thu Dec 8 00:32:06 2016 : Debug: (5) eap_ttls: <<< recv TLS 1.2 [length 0001]Thu Dec 8 00:32:06 2016 : Debug: Ignoring cbtls_msg call with pseudo content type 256, version 0Thu Dec 8 00:32:06 2016 : Debug: (5) eap_ttls: <<< recv TLS 1.2 [length 0010]Thu Dec 8 00:32:06 2016 : Debug: (5) eap_ttls: TLS_accept: SSLv3 read finished AThu Dec 8 00:32:06 2016 : Debug: Ignoring cbtls_msg call with pseudo content type 256, version 0Thu Dec 8 00:32:06 2016 : Debug: (5) eap_ttls: >>> send TLS 1.2 [length 0001]Thu Dec 8 00:32:06 2016 : Debug: (5) eap_ttls: TLS_accept: SSLv3 write change cipher spec AThu Dec 8 00:32:06 2016 : Debug: Ignoring cbtls_msg call with pseudo content type 256, version 0Thu Dec 8 00:32:06 2016 : Debug: (5) eap_ttls: >>> send TLS 1.2 [length 0010]Thu Dec 8 00:32:06 2016 : Debug: (5) eap_ttls: TLS_accept: SSLv3 write finished AThu Dec 8 00:32:06 2016 : Debug: (5) eap_ttls: TLS_accept: SSLv3 flush dataThu Dec 8 00:32:06 2016 : Debug: (5) eap_ttls: (other): SSL negotiation finished successfullyThu Dec 8 00:32:06 2016 : Debug: (5) eap_ttls: SSL Connection EstablishedThu Dec 8 00:32:06 2016 : Debug: (5) eap_ttls: [eaptls process] = handledThu Dec 8 00:32:06 2016 : Debug: (5) eap: Sending EAP Request (code 1) ID 6 length 61Thu Dec 8 00:32:06 2016 : Debug: (5) eap: EAP session adding &reply:State = 0x10c1717115c764fcThu Dec 8 00:32:06 2016 : Debug: (5) modsingle[authenticate]: returned from eap (rlm_eap) for request 5Thu Dec 8 00:32:06 2016 : Debug: (5) [eap] = handledThu Dec 8 00:32:06 2016 : Debug: (5) } # authenticate = handledThu Dec 8 00:32:06 2016 : Debug: (5) Using Post-Auth-Type ChallengeThu Dec 8 00:32:06 2016 : Debug: (5) Post-Auth-Type sub-section not found. Ignoring.Thu Dec 8 00:32:06 2016 : Debug: (5) # Executing group from file /usr/local/etc/raddb/sites-enabled/defaultThu Dec 8 00:32:06 2016 : Debug: (5) session-state: Nothing to cacheThu Dec 8 00:32:06 2016 : Debug: (5) Sent Access-Challenge Id 5 from 127.0.0.1:1812 to 127.0.0.1:54818 length 0Thu Dec 8 00:32:06 2016 : Debug: (5) EAP-Message = 0x0106003d1580000000331403030001011603030028d5b079448020ce1c9bf134d5880343cb224288a99a70bc4cffb37b4b9c97b647b0b50d6777b89330Thu Dec 8 00:32:06 2016 : Debug: (5) Message-Authenticator = 0x00000000000000000000000000000000Thu Dec 8 00:32:06 2016 : Debug: (5) State = 0x10c1717115c764fcf2a6f5bbf92adb57Thu Dec 8 00:32:06 2016 : Debug: (5) Finished requestThu Dec 8 00:32:06 2016 : Debug: Waking up in 4.9 seconds.Thu Dec 8 00:32:06 2016 : Debug: (6) Received Access-Request Id 6 from 127.0.0.1:54818 to 127.0.0.1:1812 length 197Thu Dec 8 00:32:06 2016 : Debug: (6) User-Name = "anonymous"Thu Dec 8 00:32:06 2016 : Debug: (6) NAS-IP-Address = 127.0.0.1Thu Dec 8 00:32:06 2016 : Debug: (6) Calling-Station-Id = "02-00-00-00-00-01"Thu Dec 8 00:32:06 2016 : Debug: (6) Framed-MTU = 1400Thu Dec 8 00:32:06 2016 : Debug: (6) NAS-Port-Type = Wireless-802.11Thu Dec 8 00:32:06 2016 : Debug: (6) Connect-Info = "CONNECT 11Mbps 802.11b"Thu Dec 8 00:32:06 2016 : Debug: (6) EAP-Message = 0x02060043150017030300382551dc6df862b4c1fb3201bf926b3071e7d350336ff5ef1ff5edc880e6d53e93007d8a60473a076291807fbe200f78dcc8890c11e0700e30Thu Dec 8 00:32:06 2016 : Debug: (6) State = 0x10c1717115c764fcf2a6f5bbf92adb57Thu Dec 8 00:32:06 2016 : Debug: (6) Message-Authenticator = 0x4d8fb4e15b352bea3f05a46e1b4dbeb6Thu Dec 8 00:32:06 2016 : Debug: (6) session-state: No cached attributesThu Dec 8 00:32:06 2016 : Debug: (6) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/defaultThu Dec 8 00:32:06 2016 : Debug: (6) authorize {Thu Dec 8 00:32:06 2016 : Debug: (6) policy filter_username {Thu Dec 8 00:32:06 2016 : Debug: (6) if (&User-Name) {Thu Dec 8 00:32:06 2016 : Debug: (6) if (&User-Name) -> TRUEThu Dec 8 00:32:06 2016 : Debug: (6) if (&User-Name) {Thu Dec 8 00:32:06 2016 : Debug: (6) if (&User-Name =~ / /) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (6) if (&User-Name =~ / /) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (6) if (&User-Name =~ /@[^@]*@/ ) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (6) if (&User-Name =~ /@[^@]*@/ ) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (6) if (&User-Name =~ /\.\./ ) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (6) if (&User-Name =~ /\.\./ ) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (6) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (6) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (6) if (&User-Name =~ /\.$/) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (6) if (&User-Name =~ /\.$/) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (6) if (&User-Name =~ /(a)\./) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (6) if (&User-Name =~ /(a)\./) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (6) } # if (&User-Name) = notfoundThu Dec 8 00:32:06 2016 : Debug: (6) } # policy filter_username = notfoundThu Dec 8 00:32:06 2016 : Debug: (6) modsingle[authorize]: calling preprocess (rlm_preprocess) for request 6Thu Dec 8 00:32:06 2016 : Debug: (6) modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 6Thu Dec 8 00:32:06 2016 : Debug: (6) [preprocess] = okThu Dec 8 00:32:06 2016 : Debug: (6) modsingle[authorize]: calling chap (rlm_chap) for request 6Thu Dec 8 00:32:06 2016 : Debug: (6) modsingle[authorize]: returned from chap (rlm_chap) for request 6Thu Dec 8 00:32:06 2016 : Debug: (6) [chap] = noopThu Dec 8 00:32:06 2016 : Debug: (6) modsingle[authorize]: calling mschap (rlm_mschap) for request 6Thu Dec 8 00:32:06 2016 : Debug: (6) modsingle[authorize]: returned from mschap (rlm_mschap) for request 6Thu Dec 8 00:32:06 2016 : Debug: (6) [mschap] = noopThu Dec 8 00:32:06 2016 : Debug: (6) modsingle[authorize]: calling digest (rlm_digest) for request 6Thu Dec 8 00:32:06 2016 : Debug: (6) modsingle[authorize]: returned from digest (rlm_digest) for request 6Thu Dec 8 00:32:06 2016 : Debug: (6) [digest] = noopThu Dec 8 00:32:06 2016 : Debug: (6) modsingle[authorize]: calling suffix (rlm_realm) for request 6Thu Dec 8 00:32:06 2016 : Debug: (6) suffix: Checking for suffix after "@"Thu Dec 8 00:32:06 2016 : Debug: (6) suffix: No '@' in User-Name = "anonymous", looking up realm NULLThu Dec 8 00:32:06 2016 : Debug: (6) suffix: No such realm "NULL"Thu Dec 8 00:32:06 2016 : Debug: (6) modsingle[authorize]: returned from suffix (rlm_realm) for request 6Thu Dec 8 00:32:06 2016 : Debug: (6) [suffix] = noopThu Dec 8 00:32:06 2016 : Debug: (6) modsingle[authorize]: calling eap (rlm_eap) for request 6Thu Dec 8 00:32:06 2016 : Debug: (6) eap: Peer sent EAP Response (code 2) ID 6 length 67Thu Dec 8 00:32:06 2016 : Debug: (6) eap: Continuing tunnel setupThu Dec 8 00:32:06 2016 : Debug: (6) modsingle[authorize]: returned from eap (rlm_eap) for request 6Thu Dec 8 00:32:06 2016 : Debug: (6) [eap] = okThu Dec 8 00:32:06 2016 : Debug: (6) } # authorize = okThu Dec 8 00:32:06 2016 : Debug: (6) Found Auth-Type = eapThu Dec 8 00:32:06 2016 : Debug: (6) # Executing group from file /usr/local/etc/raddb/sites-enabled/defaultThu Dec 8 00:32:06 2016 : Debug: (6) authenticate {Thu Dec 8 00:32:06 2016 : Debug: (6) modsingle[authenticate]: calling eap (rlm_eap) for request 6Thu Dec 8 00:32:06 2016 : Debug: (6) eap: Expiring EAP session with state 0x10c1717115c764fcThu Dec 8 00:32:06 2016 : Debug: (6) eap: Finished EAP session with state 0x10c1717115c764fcThu Dec 8 00:32:06 2016 : Debug: (6) eap: Previous EAP request found for state 0x10c1717115c764fc, released from the listThu Dec 8 00:32:06 2016 : Debug: (6) eap: Peer sent packet with method EAP TTLS (21)Thu Dec 8 00:32:06 2016 : Debug: (6) eap: Calling submodule eap_ttls to process dataThu Dec 8 00:32:06 2016 : Debug: (6) eap_ttls: AuthenticateThu Dec 8 00:32:06 2016 : Debug: (6) eap_ttls: Continuing EAP-TLSThu Dec 8 00:32:06 2016 : Debug: (6) eap_ttls: Peer sent flags ---Thu Dec 8 00:32:06 2016 : Debug: (6) eap_ttls: [eaptls verify] = okThu Dec 8 00:32:06 2016 : Debug: (6) eap_ttls: Done initial handshakeThu Dec 8 00:32:06 2016 : Debug: Ignoring cbtls_msg call with pseudo content type 256, version 0Thu Dec 8 00:32:06 2016 : Debug: (6) eap_ttls: [eaptls process] = okThu Dec 8 00:32:06 2016 : Debug: (6) eap_ttls: Session established. Proceeding to decode tunneled attributesThu Dec 8 00:32:06 2016 : Debug: (6) eap_ttls: Got tunneled requestThu Dec 8 00:32:06 2016 : Debug: (6) eap_ttls: EAP-Message = 0x02000018016561706f6c5f74657374406e6f6b69612e6a70Thu Dec 8 00:32:06 2016 : Debug: (6) eap_ttls: FreeRADIUS-Proxied-To = 127.0.0.1Thu Dec 8 00:32:06 2016 : Debug: (6) eap_ttls: Got tunneled identity of eapol_test(a)aikon.jpThu Dec 8 00:32:06 2016 : Debug: (6) eap_ttls: Setting default EAP type for tunneled EAP sessionThu Dec 8 00:32:06 2016 : Debug: (6) eap_ttls: Sending tunneled requestThu Dec 8 00:32:06 2016 : Debug: (6) Virtual server inner-tunnel received requestThu Dec 8 00:32:06 2016 : Debug: (6) EAP-Message = 0x02000018016561706f6c5f74657374406e6f6b69612e6a70Thu Dec 8 00:32:06 2016 : Debug: (6) FreeRADIUS-Proxied-To = 127.0.0.1Thu Dec 8 00:32:06 2016 : Debug: (6) User-Name = "eapol_test(a)aikon.jp"Thu Dec 8 00:32:06 2016 : Debug: (6) server inner-tunnel {Thu Dec 8 00:32:06 2016 : Debug: (6) session-state: No State attributeThu Dec 8 00:32:06 2016 : Debug: (6) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/inner-tunnelThu Dec 8 00:32:06 2016 : Debug: (6) authorize {Thu Dec 8 00:32:06 2016 : Debug: (6) policy filter_username {Thu Dec 8 00:32:06 2016 : Debug: (6) if (&User-Name) {Thu Dec 8 00:32:06 2016 : Debug: (6) if (&User-Name) -> TRUEThu Dec 8 00:32:06 2016 : Debug: (6) if (&User-Name) {Thu Dec 8 00:32:06 2016 : Debug: (6) if (&User-Name =~ / /) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (6) if (&User-Name =~ / /) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (6) if (&User-Name =~ /@[^@]*@/ ) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (6) if (&User-Name =~ /@[^@]*@/ ) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (6) if (&User-Name =~ /\.\./ ) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (6) if (&User-Name =~ /\.\./ ) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (6) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: Adding 1 matchesThu Dec 8 00:32:06 2016 : Debug: Clearing 1 matchesThu Dec 8 00:32:06 2016 : Debug: Adding 3 matchesThu Dec 8 00:32:06 2016 : Debug: (6) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (6) if (&User-Name =~ /\.$/) {Thu Dec 8 00:32:06 2016 : Debug: Clearing 3 matchesThu Dec 8 00:32:06 2016 : Debug: (6) if (&User-Name =~ /\.$/) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (6) if (&User-Name =~ /(a)\./) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (6) if (&User-Name =~ /(a)\./) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (6) } # if (&User-Name) = notfoundThu Dec 8 00:32:06 2016 : Debug: (6) } # policy filter_username = notfoundThu Dec 8 00:32:06 2016 : Debug: (6) modsingle[authorize]: calling chap (rlm_chap) for request 6Thu Dec 8 00:32:06 2016 : Debug: (6) modsingle[authorize]: returned from chap (rlm_chap) for request 6Thu Dec 8 00:32:06 2016 : Debug: (6) [chap] = noopThu Dec 8 00:32:06 2016 : Debug: (6) modsingle[authorize]: calling mschap (rlm_mschap) for request 6Thu Dec 8 00:32:06 2016 : Debug: (6) modsingle[authorize]: returned from mschap (rlm_mschap) for request 6Thu Dec 8 00:32:06 2016 : Debug: (6) [mschap] = noopThu Dec 8 00:32:06 2016 : Debug: (6) modsingle[authorize]: calling suffix (rlm_realm) for request 6Thu Dec 8 00:32:06 2016 : Debug: (6) suffix: Checking for suffix after "@"Thu Dec 8 00:32:06 2016 : Debug: (6) suffix: Looking up realm "aikon.jp" for User-Name = "eapol_test(a)aikon.jp"Thu Dec 8 00:32:06 2016 : Debug: (6) suffix: No such realm "aikon.jp"Thu Dec 8 00:32:06 2016 : Debug: (6) modsingle[authorize]: returned from suffix (rlm_realm) for request 6Thu Dec 8 00:32:06 2016 : Debug: (6) [suffix] = noopThu Dec 8 00:32:06 2016 : Debug: (6) update control {Thu Dec 8 00:32:06 2016 : Debug: (6) &Proxy-To-Realm := LOCALThu Dec 8 00:32:06 2016 : Debug: (6) } # update control = noopThu Dec 8 00:32:06 2016 : Debug: (6) modsingle[authorize]: calling eap (rlm_eap) for request 6Thu Dec 8 00:32:06 2016 : Debug: (6) eap: Peer sent EAP Response (code 2) ID 0 length 24Thu Dec 8 00:32:06 2016 : Debug: (6) eap: EAP-Identity reply, returning 'ok' so we can short-circuit the rest of authorizeThu Dec 8 00:32:06 2016 : Debug: (6) modsingle[authorize]: returned from eap (rlm_eap) for request 6Thu Dec 8 00:32:06 2016 : Debug: (6) [eap] = okThu Dec 8 00:32:06 2016 : Debug: (6) } # authorize = okThu Dec 8 00:32:06 2016 : Debug: (6) Found Auth-Type = eapThu Dec 8 00:32:06 2016 : Debug: (6) # Executing group from file /usr/local/etc/raddb/sites-enabled/inner-tunnelThu Dec 8 00:32:06 2016 : Debug: (6) authenticate {Thu Dec 8 00:32:06 2016 : Debug: (6) modsingle[authenticate]: calling eap (rlm_eap) for request 6Thu Dec 8 00:32:06 2016 : Debug: (6) eap: Peer sent packet with method EAP Identity (1)Thu Dec 8 00:32:06 2016 : Debug: (6) eap: Calling submodule eap_md5 to process dataThu Dec 8 00:32:06 2016 : Debug: (6) eap_md5: Issuing MD5 ChallengeThu Dec 8 00:32:06 2016 : Debug: (6) eap: Sending EAP Request (code 1) ID 1 length 22Thu Dec 8 00:32:06 2016 : Debug: (6) eap: EAP session adding &reply:State = 0x5848df875849db2aThu Dec 8 00:32:06 2016 : Debug: (6) modsingle[authenticate]: returned from eap (rlm_eap) for request 6Thu Dec 8 00:32:06 2016 : Debug: (6) [eap] = handledThu Dec 8 00:32:06 2016 : Debug: (6) } # authenticate = handledThu Dec 8 00:32:06 2016 : Debug: (6) } # server inner-tunnelThu Dec 8 00:32:06 2016 : Debug: (6) Virtual server sending replyThu Dec 8 00:32:06 2016 : Debug: (6) EAP-Message = 0x01010016041046421c99242454f962d77aa1e66b8b5eThu Dec 8 00:32:06 2016 : Debug: (6) Message-Authenticator = 0x00000000000000000000000000000000Thu Dec 8 00:32:06 2016 : Debug: (6) State = 0x5848df875849db2ae267ce7fbe5ae0c4Thu Dec 8 00:32:06 2016 : Debug: (6) eap_ttls: Got tunneled Access-ChallengeThu Dec 8 00:32:06 2016 : Debug: Ignoring cbtls_msg call with pseudo content type 256, version 0Thu Dec 8 00:32:06 2016 : Debug: (6) eap: Sending EAP Request (code 1) ID 7 length 71Thu Dec 8 00:32:06 2016 : Debug: (6) eap: EAP session adding &reply:State = 0x10c1717116c664fcThu Dec 8 00:32:06 2016 : Debug: (6) modsingle[authenticate]: returned from eap (rlm_eap) for request 6Thu Dec 8 00:32:06 2016 : Debug: (6) [eap] = handledThu Dec 8 00:32:06 2016 : Debug: (6) } # authenticate = handledThu Dec 8 00:32:06 2016 : Debug: (6) Using Post-Auth-Type ChallengeThu Dec 8 00:32:06 2016 : Debug: (6) Post-Auth-Type sub-section not found. Ignoring.Thu Dec 8 00:32:06 2016 : Debug: (6) # Executing group from file /usr/local/etc/raddb/sites-enabled/defaultThu Dec 8 00:32:06 2016 : Debug: (6) session-state: Nothing to cacheThu Dec 8 00:32:06 2016 : Debug: (6) Sent Access-Challenge Id 6 from 127.0.0.1:1812 to 127.0.0.1:54818 length 0Thu Dec 8 00:32:06 2016 : Debug: (6) EAP-Message = 0x0107004715800000003d1703030038d5b079448020ce1df42a341c4d030197afb3c4041e27f8465ff2d7f896aa3ab4433ffeebe6810b7579683e59ad495d7578d1c571bd339e54Thu Dec 8 00:32:06 2016 : Debug: (6) Message-Authenticator = 0x00000000000000000000000000000000Thu Dec 8 00:32:06 2016 : Debug: (6) State = 0x10c1717116c664fcf2a6f5bbf92adb57Thu Dec 8 00:32:06 2016 : Debug: (6) Finished requestThu Dec 8 00:32:06 2016 : Debug: Waking up in 4.9 seconds.Thu Dec 8 00:32:06 2016 : Debug: (7) Received Access-Request Id 7 from 127.0.0.1:54818 to 127.0.0.1:1812 length 197Thu Dec 8 00:32:06 2016 : Debug: (7) User-Name = "anonymous"Thu Dec 8 00:32:06 2016 : Debug: (7) NAS-IP-Address = 127.0.0.1Thu Dec 8 00:32:06 2016 : Debug: (7) Calling-Station-Id = "02-00-00-00-00-01"Thu Dec 8 00:32:06 2016 : Debug: (7) Framed-MTU = 1400Thu Dec 8 00:32:06 2016 : Debug: (7) NAS-Port-Type = Wireless-802.11Thu Dec 8 00:32:06 2016 : Debug: (7) Connect-Info = "CONNECT 11Mbps 802.11b"Thu Dec 8 00:32:06 2016 : Debug: (7) EAP-Message = 0x02070043150017030300382551dc6df862b4c2cdd2391feaa04414f9442a24998738878a8bdab227da23be15154d2585607e7be9088483a675011b99bb783380c85edbThu Dec 8 00:32:06 2016 : Debug: (7) State = 0x10c1717116c664fcf2a6f5bbf92adb57Thu Dec 8 00:32:06 2016 : Debug: (7) Message-Authenticator = 0x3206542628e88eab17036a42d150300bThu Dec 8 00:32:06 2016 : Debug: (7) session-state: No cached attributesThu Dec 8 00:32:06 2016 : Debug: (7) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/defaultThu Dec 8 00:32:06 2016 : Debug: (7) authorize {Thu Dec 8 00:32:06 2016 : Debug: (7) policy filter_username {Thu Dec 8 00:32:06 2016 : Debug: (7) if (&User-Name) {Thu Dec 8 00:32:06 2016 : Debug: (7) if (&User-Name) -> TRUEThu Dec 8 00:32:06 2016 : Debug: (7) if (&User-Name) {Thu Dec 8 00:32:06 2016 : Debug: (7) if (&User-Name =~ / /) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (7) if (&User-Name =~ / /) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (7) if (&User-Name =~ /@[^@]*@/ ) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (7) if (&User-Name =~ /@[^@]*@/ ) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (7) if (&User-Name =~ /\.\./ ) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (7) if (&User-Name =~ /\.\./ ) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (7) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (7) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (7) if (&User-Name =~ /\.$/) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (7) if (&User-Name =~ /\.$/) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (7) if (&User-Name =~ /(a)\./) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (7) if (&User-Name =~ /(a)\./) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (7) } # if (&User-Name) = notfoundThu Dec 8 00:32:06 2016 : Debug: (7) } # policy filter_username = notfoundThu Dec 8 00:32:06 2016 : Debug: (7) modsingle[authorize]: calling preprocess (rlm_preprocess) for request 7Thu Dec 8 00:32:06 2016 : Debug: (7) modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 7Thu Dec 8 00:32:06 2016 : Debug: (7) [preprocess] = okThu Dec 8 00:32:06 2016 : Debug: (7) modsingle[authorize]: calling chap (rlm_chap) for request 7Thu Dec 8 00:32:06 2016 : Debug: (7) modsingle[authorize]: returned from chap (rlm_chap) for request 7Thu Dec 8 00:32:06 2016 : Debug: (7) [chap] = noopThu Dec 8 00:32:06 2016 : Debug: (7) modsingle[authorize]: calling mschap (rlm_mschap) for request 7Thu Dec 8 00:32:06 2016 : Debug: (7) modsingle[authorize]: returned from mschap (rlm_mschap) for request 7Thu Dec 8 00:32:06 2016 : Debug: (7) [mschap] = noopThu Dec 8 00:32:06 2016 : Debug: (7) modsingle[authorize]: calling digest (rlm_digest) for request 7Thu Dec 8 00:32:06 2016 : Debug: (7) modsingle[authorize]: returned from digest (rlm_digest) for request 7Thu Dec 8 00:32:06 2016 : Debug: (7) [digest] = noopThu Dec 8 00:32:06 2016 : Debug: (7) modsingle[authorize]: calling suffix (rlm_realm) for request 7Thu Dec 8 00:32:06 2016 : Debug: (7) suffix: Checking for suffix after "@"Thu Dec 8 00:32:06 2016 : Debug: (7) suffix: No '@' in User-Name = "anonymous", looking up realm NULLThu Dec 8 00:32:06 2016 : Debug: (7) suffix: No such realm "NULL"Thu Dec 8 00:32:06 2016 : Debug: (7) modsingle[authorize]: returned from suffix (rlm_realm) for request 7Thu Dec 8 00:32:06 2016 : Debug: (7) [suffix] = noopThu Dec 8 00:32:06 2016 : Debug: (7) modsingle[authorize]: calling eap (rlm_eap) for request 7Thu Dec 8 00:32:06 2016 : Debug: (7) eap: Peer sent EAP Response (code 2) ID 7 length 67Thu Dec 8 00:32:06 2016 : Debug: (7) eap: Continuing tunnel setupThu Dec 8 00:32:06 2016 : Debug: (7) modsingle[authorize]: returned from eap (rlm_eap) for request 7Thu Dec 8 00:32:06 2016 : Debug: (7) [eap] = okThu Dec 8 00:32:06 2016 : Debug: (7) } # authorize = okThu Dec 8 00:32:06 2016 : Debug: (7) Found Auth-Type = eapThu Dec 8 00:32:06 2016 : Debug: (7) # Executing group from file /usr/local/etc/raddb/sites-enabled/defaultThu Dec 8 00:32:06 2016 : Debug: (7) authenticate {Thu Dec 8 00:32:06 2016 : Debug: (7) modsingle[authenticate]: calling eap (rlm_eap) for request 7Thu Dec 8 00:32:06 2016 : Debug: (7) eap: Expiring EAP session with state 0x5848df875849db2aThu Dec 8 00:32:06 2016 : Debug: (7) eap: Finished EAP session with state 0x10c1717116c664fcThu Dec 8 00:32:06 2016 : Debug: (7) eap: Previous EAP request found for state 0x10c1717116c664fc, released from the listThu Dec 8 00:32:06 2016 : Debug: (7) eap: Peer sent packet with method EAP TTLS (21)Thu Dec 8 00:32:06 2016 : Debug: (7) eap: Calling submodule eap_ttls to process dataThu Dec 8 00:32:06 2016 : Debug: (7) eap_ttls: AuthenticateThu Dec 8 00:32:06 2016 : Debug: (7) eap_ttls: Continuing EAP-TLSThu Dec 8 00:32:06 2016 : Debug: (7) eap_ttls: Peer sent flags ---Thu Dec 8 00:32:06 2016 : Debug: (7) eap_ttls: [eaptls verify] = okThu Dec 8 00:32:06 2016 : Debug: (7) eap_ttls: Done initial handshakeThu Dec 8 00:32:06 2016 : Debug: Ignoring cbtls_msg call with pseudo content type 256, version 0Thu Dec 8 00:32:06 2016 : Debug: (7) eap_ttls: [eaptls process] = okThu Dec 8 00:32:06 2016 : Debug: (7) eap_ttls: Session established. Proceeding to decode tunneled attributesThu Dec 8 00:32:06 2016 : Debug: (7) eap_ttls: Got tunneled requestThu Dec 8 00:32:06 2016 : Debug: (7) eap_ttls: EAP-Message = 0x020100160410247c68784de86a2369dd6851989c7746Thu Dec 8 00:32:06 2016 : Debug: (7) eap_ttls: FreeRADIUS-Proxied-To = 127.0.0.1Thu Dec 8 00:32:06 2016 : Debug: (7) eap_ttls: Sending tunneled requestThu Dec 8 00:32:06 2016 : Debug: (7) Virtual server inner-tunnel received requestThu Dec 8 00:32:06 2016 : Debug: (7) EAP-Message = 0x020100160410247c68784de86a2369dd6851989c7746Thu Dec 8 00:32:06 2016 : Debug: (7) FreeRADIUS-Proxied-To = 127.0.0.1Thu Dec 8 00:32:06 2016 : Debug: (7) User-Name = "eapol_test(a)aikon.jp"Thu Dec 8 00:32:06 2016 : Debug: (7) State = 0x5848df875849db2ae267ce7fbe5ae0c4Thu Dec 8 00:32:06 2016 : Debug: (7) server inner-tunnel {Thu Dec 8 00:32:06 2016 : Debug: (7) session-state: No cached attributesThu Dec 8 00:32:06 2016 : Debug: (7) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/inner-tunnelThu Dec 8 00:32:06 2016 : Debug: (7) authorize {Thu Dec 8 00:32:06 2016 : Debug: (7) policy filter_username {Thu Dec 8 00:32:06 2016 : Debug: (7) if (&User-Name) {Thu Dec 8 00:32:06 2016 : Debug: (7) if (&User-Name) -> TRUEThu Dec 8 00:32:06 2016 : Debug: (7) if (&User-Name) {Thu Dec 8 00:32:06 2016 : Debug: (7) if (&User-Name =~ / /) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (7) if (&User-Name =~ / /) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (7) if (&User-Name =~ /@[^@]*@/ ) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (7) if (&User-Name =~ /@[^@]*@/ ) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (7) if (&User-Name =~ /\.\./ ) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (7) if (&User-Name =~ /\.\./ ) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (7) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: Adding 1 matchesThu Dec 8 00:32:06 2016 : Debug: Clearing 1 matchesThu Dec 8 00:32:06 2016 : Debug: Adding 3 matchesThu Dec 8 00:32:06 2016 : Debug: (7) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (7) if (&User-Name =~ /\.$/) {Thu Dec 8 00:32:06 2016 : Debug: Clearing 3 matchesThu Dec 8 00:32:06 2016 : Debug: (7) if (&User-Name =~ /\.$/) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (7) if (&User-Name =~ /(a)\./) {Thu Dec 8 00:32:06 2016 : Debug: No matchesThu Dec 8 00:32:06 2016 : Debug: (7) if (&User-Name =~ /(a)\./) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (7) } # if (&User-Name) = notfoundThu Dec 8 00:32:06 2016 : Debug: (7) } # policy filter_username = notfoundThu Dec 8 00:32:06 2016 : Debug: (7) modsingle[authorize]: calling chap (rlm_chap) for request 7Thu Dec 8 00:32:06 2016 : Debug: (7) modsingle[authorize]: returned from chap (rlm_chap) for request 7Thu Dec 8 00:32:06 2016 : Debug: (7) [chap] = noopThu Dec 8 00:32:06 2016 : Debug: (7) modsingle[authorize]: calling mschap (rlm_mschap) for request 7Thu Dec 8 00:32:06 2016 : Debug: (7) modsingle[authorize]: returned from mschap (rlm_mschap) for request 7Thu Dec 8 00:32:06 2016 : Debug: (7) [mschap] = noopThu Dec 8 00:32:06 2016 : Debug: (7) modsingle[authorize]: calling suffix (rlm_realm) for request 7Thu Dec 8 00:32:06 2016 : Debug: (7) suffix: Checking for suffix after "@"Thu Dec 8 00:32:06 2016 : Debug: (7) suffix: Looking up realm "aikon.jp" for User-Name = "eapol_test(a)aikon.jp"Thu Dec 8 00:32:06 2016 : Debug: (7) suffix: No such realm "aikon.jp"Thu Dec 8 00:32:06 2016 : Debug: (7) modsingle[authorize]: returned from suffix (rlm_realm) for request 7Thu Dec 8 00:32:06 2016 : Debug: (7) [suffix] = noopThu Dec 8 00:32:06 2016 : Debug: (7) update control {Thu Dec 8 00:32:06 2016 : Debug: (7) &Proxy-To-Realm := LOCALThu Dec 8 00:32:06 2016 : Debug: (7) } # update control = noopThu Dec 8 00:32:06 2016 : Debug: (7) modsingle[authorize]: calling eap (rlm_eap) for request 7Thu Dec 8 00:32:06 2016 : Debug: (7) eap: Peer sent EAP Response (code 2) ID 1 length 22Thu Dec 8 00:32:06 2016 : Debug: (7) eap: No EAP Start, assuming it's an on-going EAP conversationThu Dec 8 00:32:06 2016 : Debug: (7) modsingle[authorize]: returned from eap (rlm_eap) for request 7Thu Dec 8 00:32:06 2016 : Debug: (7) [eap] = updatedThu Dec 8 00:32:06 2016 : Debug: (7) modsingle[authorize]: calling files (rlm_files) for request 7Thu Dec 8 00:32:06 2016 : Debug: (7) modsingle[authorize]: returned from files (rlm_files) for request 7Thu Dec 8 00:32:06 2016 : Debug: (7) [files] = noopThu Dec 8 00:32:06 2016 : Debug: (7) modsingle[authorize]: calling expiration (rlm_expiration) for request 7Thu Dec 8 00:32:06 2016 : Debug: (7) modsingle[authorize]: returned from expiration (rlm_expiration) for request 7Thu Dec 8 00:32:06 2016 : Debug: (7) [expiration] = noopThu Dec 8 00:32:06 2016 : Debug: (7) modsingle[authorize]: calling logintime (rlm_logintime) for request 7Thu Dec 8 00:32:06 2016 : Debug: (7) modsingle[authorize]: returned from logintime (rlm_logintime) for request 7Thu Dec 8 00:32:06 2016 : Debug: (7) [logintime] = noopThu Dec 8 00:32:06 2016 : Debug: (7) modsingle[authorize]: calling pap (rlm_pap) for request 7Thu Dec 8 00:32:06 2016 : Debug: (7) modsingle[authorize]: returned from pap (rlm_pap) for request 7Thu Dec 8 00:32:06 2016 : Debug: (7) [pap] = noopThu Dec 8 00:32:06 2016 : Debug: (7) } # authorize = updatedThu Dec 8 00:32:06 2016 : Debug: (7) Found Auth-Type = eapThu Dec 8 00:32:06 2016 : Debug: (7) # Executing group from file /usr/local/etc/raddb/sites-enabled/inner-tunnelThu Dec 8 00:32:06 2016 : Debug: (7) authenticate {Thu Dec 8 00:32:06 2016 : Debug: (7) modsingle[authenticate]: calling eap (rlm_eap) for request 7Thu Dec 8 00:32:06 2016 : Debug: (7) eap: Expiring EAP session with state 0x5848df875849db2aThu Dec 8 00:32:06 2016 : Debug: (7) eap: Finished EAP session with state 0x5848df875849db2aThu Dec 8 00:32:06 2016 : Debug: (7) eap: Previous EAP request found for state 0x5848df875849db2a, released from the listThu Dec 8 00:32:06 2016 : Debug: (7) eap: Peer sent packet with method EAP MD5 (4)Thu Dec 8 00:32:06 2016 : Debug: (7) eap: Calling submodule eap_md5 to process dataThu Dec 8 00:32:06 2016 : Debug: (7) eap_md5: Cleartext-Password is required for EAP-MD5 authenticationThu Dec 8 00:32:06 2016 : ERROR: (7) eap: Failed continuing EAP MD5 (4) session. EAP sub-module failedThu Dec 8 00:32:06 2016 : Debug: (7) eap: Sending EAP Failure (code 4) ID 1 length 4Thu Dec 8 00:32:06 2016 : Debug: (7) eap: Failed in EAP selectThu Dec 8 00:32:06 2016 : Debug: (7) modsingle[authenticate]: returned from eap (rlm_eap) for request 7Thu Dec 8 00:32:06 2016 : Debug: (7) [eap] = invalidThu Dec 8 00:32:06 2016 : Debug: (7) } # authenticate = invalidThu Dec 8 00:32:06 2016 : Debug: (7) Failed to authenticate the userThu Dec 8 00:32:06 2016 : Auth: (7) Login incorrect (eap: Failed continuing EAP MD5 (4) session. EAP sub-module failed): [eapol_test(a)aikon.jp] (from client localhost port 0 via TLS tunnel)Thu Dec 8 00:32:06 2016 : Debug: (7) Using Post-Auth-Type RejectThu Dec 8 00:32:06 2016 : Debug: (7) # Executing group from file /usr/local/etc/raddb/sites-enabled/inner-tunnelThu Dec 8 00:32:06 2016 : Debug: (7) Post-Auth-Type REJECT {Thu Dec 8 00:32:06 2016 : Debug: (7) modsingle[post-auth]: calling attr_filter.access_reject (rlm_attr_filter) for request 7Thu Dec 8 00:32:06 2016 : Debug: %{User-Name}Thu Dec 8 00:32:06 2016 : Debug: Parsed xlat tree:Thu Dec 8 00:32:06 2016 : Debug: attribute --> User-NameThu Dec 8 00:32:06 2016 : Debug: (7) attr_filter.access_reject: EXPAND %{User-Name}Thu Dec 8 00:32:06 2016 : Debug: (7) attr_filter.access_reject: --> eapol_test(a)aikon.jpThu Dec 8 00:32:06 2016 : Debug: (7) attr_filter.access_reject: Matched entry DEFAULT at line 11Thu Dec 8 00:32:06 2016 : Debug: (7) attr_filter.access_reject: EAP-Message = 0x04010004 allowed by EAP-Message =* 0xThu Dec 8 00:32:06 2016 : Debug: (7) attr_filter.access_reject: Attribute "EAP-Message" allowed by 1 rules, disallowed by 0 rulesThu Dec 8 00:32:06 2016 : Debug: (7) attr_filter.access_reject: Message-Authenticator = 0x00000000000000000000000000000000 allowed by Message-Authenticator =* 0xThu Dec 8 00:32:06 2016 : Debug: (7) attr_filter.access_reject: Attribute "Message-Authenticator" allowed by 1 rules, disallowed by 0 rulesThu Dec 8 00:32:06 2016 : Debug: (7) modsingle[post-auth]: returned from attr_filter.access_reject (rlm_attr_filter) for request 7Thu Dec 8 00:32:06 2016 : Debug: (7) [attr_filter.access_reject] = updatedThu Dec 8 00:32:06 2016 : Debug: (7) update outer.session-state {Thu Dec 8 00:32:06 2016 : Debug: (7) &Module-Failure-Message := &request:Module-Failure-Message -> 'eap: Failed continuing EAP MD5 (4) session. EAP sub-module failed'Thu Dec 8 00:32:06 2016 : Debug: (7) } # update outer.session-state = noopThu Dec 8 00:32:06 2016 : Debug: (7) } # Post-Auth-Type REJECT = updatedThu Dec 8 00:32:06 2016 : Debug: (7) } # server inner-tunnelThu Dec 8 00:32:06 2016 : Debug: (7) Virtual server sending replyThu Dec 8 00:32:06 2016 : Debug: (7) EAP-Message = 0x04010004Thu Dec 8 00:32:06 2016 : Debug: (7) Message-Authenticator = 0x00000000000000000000000000000000Thu Dec 8 00:32:06 2016 : Debug: (7) eap_ttls: Got tunneled Access-RejectThu Dec 8 00:32:06 2016 : ERROR: (7) eap: Failed continuing EAP TTLS (21) session. EAP sub-module failedThu Dec 8 00:32:06 2016 : Debug: (7) eap: Sending EAP Failure (code 4) ID 7 length 4Thu Dec 8 00:32:06 2016 : Debug: (7) eap: Failed in EAP selectThu Dec 8 00:32:06 2016 : Debug: (7) modsingle[authenticate]: returned from eap (rlm_eap) for request 7Thu Dec 8 00:32:06 2016 : Debug: (7) [eap] = invalidThu Dec 8 00:32:06 2016 : Debug: (7) } # authenticate = invalidThu Dec 8 00:32:06 2016 : Debug: (7) Failed to authenticate the userThu Dec 8 00:32:06 2016 : Auth: (7) Login incorrect (eap: Failed continuing EAP TTLS (21) session. EAP sub-module failed): [anonymous] (from client localhost port 0 cli 02-00-00-00-00-01)Thu Dec 8 00:32:06 2016 : Debug: (7) Using Post-Auth-Type RejectThu Dec 8 00:32:06 2016 : Debug: (7) # Executing group from file /usr/local/etc/raddb/sites-enabled/defaultThu Dec 8 00:32:06 2016 : Debug: (7) Post-Auth-Type REJECT {Thu Dec 8 00:32:06 2016 : Debug: (7) modsingle[post-auth]: calling attr_filter.access_reject (rlm_attr_filter) for request 7Thu Dec 8 00:32:06 2016 : Debug: %{User-Name}Thu Dec 8 00:32:06 2016 : Debug: Parsed xlat tree:Thu Dec 8 00:32:06 2016 : Debug: attribute --> User-NameThu Dec 8 00:32:06 2016 : Debug: (7) attr_filter.access_reject: EXPAND %{User-Name}Thu Dec 8 00:32:06 2016 : Debug: (7) attr_filter.access_reject: --> anonymousThu Dec 8 00:32:06 2016 : Debug: (7) attr_filter.access_reject: Matched entry DEFAULT at line 11Thu Dec 8 00:32:06 2016 : Debug: (7) attr_filter.access_reject: EAP-Message = 0x04070004 allowed by EAP-Message =* 0xThu Dec 8 00:32:06 2016 : Debug: (7) attr_filter.access_reject: Attribute "EAP-Message" allowed by 1 rules, disallowed by 0 rulesThu Dec 8 00:32:06 2016 : Debug: (7) attr_filter.access_reject: Message-Authenticator = 0x00000000000000000000000000000000 allowed by Message-Authenticator =* 0xThu Dec 8 00:32:06 2016 : Debug: (7) attr_filter.access_reject: Attribute "Message-Authenticator" allowed by 1 rules, disallowed by 0 rulesThu Dec 8 00:32:06 2016 : Debug: (7) modsingle[post-auth]: returned from attr_filter.access_reject (rlm_attr_filter) for request 7Thu Dec 8 00:32:06 2016 : Debug: (7) [attr_filter.access_reject] = updatedThu Dec 8 00:32:06 2016 : Debug: (7) modsingle[post-auth]: calling eap (rlm_eap) for request 7Thu Dec 8 00:32:06 2016 : Debug: (7) eap: Reply already contained an EAP-Message, not inserting EAP-FailureThu Dec 8 00:32:06 2016 : Debug: (7) modsingle[post-auth]: returned from eap (rlm_eap) for request 7Thu Dec 8 00:32:06 2016 : Debug: (7) [eap] = noopThu Dec 8 00:32:06 2016 : Debug: (7) policy remove_reply_message_if_eap {Thu Dec 8 00:32:06 2016 : Debug: (7) if (&reply:EAP-Message && &reply:Reply-Message) {Thu Dec 8 00:32:06 2016 : Debug: (7) if (&reply:EAP-Message && &reply:Reply-Message) -> FALSEThu Dec 8 00:32:06 2016 : Debug: (7) else {Thu Dec 8 00:32:06 2016 : Debug: (7) modsingle[post-auth]: calling noop (rlm_always) for request 7Thu Dec 8 00:32:06 2016 : Debug: (7) modsingle[post-auth]: returned from noop (rlm_always) for request 7Thu Dec 8 00:32:06 2016 : Debug: (7) [noop] = noopThu Dec 8 00:32:06 2016 : Debug: (7) } # else = noopThu Dec 8 00:32:06 2016 : Debug: (7) } # policy remove_reply_message_if_eap = noopThu Dec 8 00:32:06 2016 : Debug: (7) } # Post-Auth-Type REJECT = updatedThu Dec 8 00:32:06 2016 : Debug: (7) Delaying response for 1.000000 secondsThu Dec 8 00:32:06 2016 : Debug: Waking up in 0.3 seconds.Thu Dec 8 00:32:06 2016 : Debug: Waking up in 0.6 seconds.Thu Dec 8 00:32:07 2016 : Debug: (7) Sending delayed responseThu Dec 8 00:32:07 2016 : Debug: (7) Sent Access-Reject Id 7 from 127.0.0.1:1812 to 127.0.0.1:54818 length 44Thu Dec 8 00:32:07 2016 : Debug: (7) EAP-Message = 0x04070004Thu Dec 8 00:32:07 2016 : Debug: (7) Message-Authenticator = 0x00000000000000000000000000000000Thu Dec 8 00:32:07 2016 : Debug: Waking up in 3.9 seconds.Thu Dec 8 00:32:11 2016 : Debug: (0) Cleaning up request packet ID 0 with timestamp +204Thu Dec 8 00:32:11 2016 : Debug: (1) Cleaning up request packet ID 1 with timestamp +204Thu Dec 8 00:32:11 2016 : Debug: (2) Cleaning up request packet ID 2 with timestamp +204Thu Dec 8 00:32:11 2016 : Debug: (3) Cleaning up request packet ID 3 with timestamp +204Thu Dec 8 00:32:11 2016 : Debug: (4) Cleaning up request packet ID 4 with timestamp +204Thu Dec 8 00:32:11 2016 : Debug: (5) Cleaning up request packet ID 5 with timestamp +204Thu Dec 8 00:32:11 2016 : Debug: (6) Cleaning up request packet ID 6 with timestamp +204Thu Dec 8 00:32:11 2016 : Debug: (7) Cleaning up request packet ID 7 with timestamp +204Thu Dec 8 00:32:11 2016 : Info: Ready to process requests
2
2
Hello,
I have FreeRADIUS running with a sql database in production. I am using the
sql database to set user's check and reply attributes. The problem I have
is that there are some attributes that I need to set them at runtime
depending on the NAS identity (or any other FreeRADIUS variable), so I have
to edit the configuration file and add something like this:
if (...) {
update control {
Pool-Name := "%{NAS-Identifier}"
}
}
Please, ignore the fact that I am updating the Pool-Name attribute. It is
just an example but it has sense in my case to let users switch between NAS
and IP pools automatically.
I want to be able to use variables in attributes column (for radcheck,
radreply, radgroupcheck, and radgroupreply tables). Then FreeRADIUS will
get those values for attributes and expand or evaluate them replacing
variable placeholders for concrete values. I don't want to modify the
configuration file to store any user's configuration as I am currently
doing.
Will that feature make sense? I can help in programming it or even make a
donation to have someone help me in doing this.
I post a request on Github:
https://github.com/FreeRADIUS/freeradius-server/issues/1870
I was suggested to use SQL xlat expansion %{sql:SELECT ...} but that is not
useful in my case because I don't want to customize requests.
Regards,
Javier
2
5
o.k back to 3.0
[Sorry Alan B, finger trouble sent the partial message before]
I'm using a local CA authority with appropriate root and intermediate certs
Root Cert is
*Certificate Information:**Common Name:* University of York Root CA I
*Organization:* University of York*Organization Unit:* IT Services
*Locality:* York*State:* North Yorkshire*Country:* GB*Valid From:*
September 13, 2015*Valid To:* October 13, 2035*Issuer:* University of York
Root CA I, University of York*Serial Number:* .....
Intermediate Cert is
*Certificate Information:**Common Name:* University of York Intermediate CA
I*Organization:* University of York*Organization Unit:* IT Services
*Locality:* York*State:* North Yorkshire*Country:* GB*Valid From:*
September 13, 2015*Valid To:* October 13, 2035*Issuer:* University of York
Root CA I, University of York*Serial Number:* ....
and the cert is
*Certificate Information:**Common Name:* radsec.york.ac.uk*Organization:*
University of York*Organization Unit:* IT Services*Locality:* York*State:*
North Yorkshire*Country:* GB*Valid From:* November 10, 2015*Valid To:*
December 6, 2017*Issuer:* University of York Intermediate CA I, University
of York*Serial Number:* .....
Sending server
In /etc/freeradius/sites-enabled/tls I have
home_server prodn2.sharaz.info {
ipv6addr = 2a03:b0c0:1:a1::a9f:8001
port = 2083
type = auth
secret = radsec
proto = tcp
status_check = none
tls {
certdir = ${confdir}/certs/UoY/radsec-certs
private_key_password = "< secret key>"
private_key_file = ${certdir}/radsecyorkacuk.key
# If ca_file (below) is not used, then the
# certificate_file below MUST include not
# only the server certificate, but ALSO all
# of the CA certificates used to sign the
# server certificate.
certificate_file = ${certdir}/certAndCAs.pem
# Trusted Root CA list
#
# ALL of the CA's in this list will be trusted
# to issue client certificates for authentication.
#
# In general, you should use self-signed
# certificates for 802.1x (EAP) authentication.
# In that case, this CA file should contain
# *one* CA certificate
# ca_file = .........
dh_file = ${confdir}/certs/dh
random_file = /dev/urandom
fragment_size = 1024
include_length = yes
cipher_list = "DEFAULT"
}
}
On the receiving server in /etc/freeradius/sites-enabled/tls I've got
listen {
ipv6addr = *
port = 2083
#
# TCP and TLS sockets can accept Access-Request and
# Accounting-Request on the same socket.
#
# auth = only Access-Request
# acct = only Accounting-Request
# auth+acct = both
#
type = auth+acct
# For now, only TCP transport is allowed.
proto = tcp
# Send packets to the default virtual server
virtual_server = eduroam
clients = radsec
.....
tls {
private_key_password = "A key"
private_key_file =
${certdir}/UoY/radsec-certs/radsecyorkacuk.key
# If Private key & Certificate are located in
# the same file, then private_key_file &
# certificate_file must contain the same file
# name.
#
# If ca_file (below) is not used, then the
# certificate_file below MUST include not
# only the server certificate, but ALSO all
# of the CA certificates used to sign the
# server certificate.
# File contents = cp cert.pem certAndCAs.peml;cat
radsecIntermediateCA.pem>>certAndCAs.pem;
# cat radsecRootCA>>certAndCAs.pem
certificate_file =
${certdir}/UoY/radsec-certs/certAndCAs.pem
# Trusted Root CA list
#
# ALL of the CA's in this list will be trusted
# to issue client certificates for authentication.
#
# In general, you should use self-signed
# certificates for 802.1x (EAP) authentication.
# In that case, this CA file should contain
# *one* CA certificate.
#
# This parameter is used only for EAP-TLS,
# when you issue client certificates. If you do
# not use client certificates, and you do not want
# to permit EAP-TLS authentication, then delete
# this configuration item.
#ca_file = ${cadir}/UoY/radsec-certs/radsecRoot.pem
dh_file = ${certdir}/dh
fragment_size = 8192
cipher_list = "DEFAULT"
cache {
lifetime = 24
}
require_client_cert = yes
}
}
clients radsec {
client dn0.sharaz.info {
ipv6addr = 2a01:348:6:59d::2
proto = tls
secret = radsec
}
.....
When I run eapol_test , on the receiving server I get
Fri Dec 9 10:49:55 2016 : Debug: ... new connection request on TCP socket
Fri Dec 9 10:49:55 2016 : Debug: Listening on auth+acct from client
(2a01:348:6:59d::2, 60616) -> (::, 2083, virtual-server=eduroam)
Fri Dec 9 10:49:55 2016 : Debug: Waking up in 0.4 seconds.
Fri Dec 9 10:49:55 2016 : Debug: (0) Initiating new EAP-TLS session
Fri Dec 9 10:49:55 2016 : Debug: (0) Setting verify mode to require
certificate from client
Fri Dec 9 10:49:55 2016 : Debug: (0) Reading from socket 18
READ FROM SSL 291
00: 16 03 01 01 1e 01 00 01 1a 03 03 28 e9 b0 c4 4e
.....
Fri Dec 9 10:49:55 2016 : Debug: (0) (other): before/accept initialization
Fri Dec 9 10:49:55 2016 : Debug: (0) TLS_accept: before/accept
initialization
Fri Dec 9 10:49:55 2016 : Debug: Ignoring cbtls_msg call with pseudo
content type 256, version 0
Fri Dec 9 10:49:55 2016 : Debug: (0) <<< recv TLS 1.2 [length 011e]
Fri Dec 9 10:49:55 2016 : Debug: (0) TLS_accept: unknown state
Fri Dec 9 10:49:55 2016 : Debug: Ignoring cbtls_msg call with pseudo
content type 256, version 0
Fri Dec 9 10:49:55 2016 : Debug: (0) >>> send TLS 1.2 [length 003e]
Fri Dec 9 10:49:55 2016 : Debug: (0) TLS_accept: unknown state
Fri Dec 9 10:49:55 2016 : Debug: Ignoring cbtls_msg call with pseudo
content type 256, version 0
Fri Dec 9 10:49:55 2016 : Debug: (0) >>> send TLS 1.2 [length 0fb3]
Fri Dec 9 10:49:55 2016 : Debug: (0) TLS_accept: unknown state
Fri Dec 9 10:49:55 2016 : Debug: Ignoring cbtls_msg call with pseudo
content type 256, version 0
Fri Dec 9 10:49:55 2016 : Debug: (0) >>> send TLS 1.2 [length 014d]
Fri Dec 9 10:49:55 2016 : Debug: (0) TLS_accept: unknown state
Fri Dec 9 10:49:55 2016 : Debug: Ignoring cbtls_msg call with pseudo
content type 256, version 0
Fri Dec 9 10:49:55 2016 : Debug: (0) >>> send TLS 1.2 [length 002e]
Fri Dec 9 10:49:55 2016 : Debug: (0) TLS_accept: unknown state
Fri Dec 9 10:49:55 2016 : Debug: (0) TLS_accept: unknown state
Fri Dec 9 10:49:55 2016 : Debug: (0) TLS_accept: Need to read more data:
unknown state
Fri Dec 9 10:49:55 2016 : Debug: (0) TLS_accept: Need to read more data:
unknown state
Fri Dec 9 10:49:55 2016 : Debug: (0) In SSL Handshake Phase
Fri Dec 9 10:49:55 2016 : Debug: (0) In SSL Accept mode
Fri Dec 9 10:49:55 2016 : Debug: (0) Writing to socket 18
Fri Dec 9 10:49:55 2016 : Debug: Waking up in 0.4 seconds.
READ FROM SSL 7
00: 15 03 03 00 02 02 30
Fri Dec 9 10:49:55 2016 : Debug: Ignoring cbtls_msg call with pseudo
content type 256, version 0
Fri Dec 9 10:49:55 2016 : Debug: (0) <<< recv TLS 1.2 [length 0002]
Fri Dec 9 10:49:55 2016 : ERROR: (0) TLS Alert read:fatal:unknown CA
Fri Dec 9 10:49:55 2016 : ERROR: (0) TLS_accept: Failed in unknown state
Fri Dec 9 10:49:55 2016 : ERROR: (0) Failed in __FUNCTION__ (SSL_read)
Fri Dec 9 10:49:55 2016 : ERROR: (0) s3_pkt.c[1472]:error:14094418:SSL
routines:ssl3_read_bytes:tlsv1 alert unknown ca
Fri Dec 9 10:49:55 2016 : ERROR: (0) s3_pkt.c[1210]:error:140940E5:SSL
routines:ssl3_read_bytes:ssl handshake failure
Fri Dec 9 10:49:55 2016 : ERROR: (0) System call (I/O) error (-1)
Fri Dec 9 10:49:55 2016 : Debug: (0) FAILED in TLS handshake receive
Fri Dec 9 10:49:55 2016 : Debug: Closing TLS socket from client port 60616
Fri Dec 9 10:49:55 2016 : Debug: Client has closed connection
Fri Dec 9 10:49:55 2016 : Info: ... shutting down socket auth+acct from
client (2a01:348:6:59d::2, 60616) -> (::, 2083, virtual-server=eduroam)
Fri Dec 9 10:49:55 2016 : Debug: Waking up in 2.9 seconds.
On the sending server it says
Fri Dec 9 10:49:55 2016 : Debug: (4) proxy: Trying to allocate ID (0/2)
Fri Dec 9 10:49:55 2016 : Debug: (4) proxy: Trying to open a new listener
to the home server
Fri Dec 9 10:49:55 2016 : Debug: Trying SSL to port 2083
Fri Dec 9 10:49:55 2016 : Debug: Requiring Server certificate
Fri Dec 9 10:49:55 2016 : Debug: (0) (other): before/connect initialization
Fri Dec 9 10:49:55 2016 : Debug: (0) TLS_connect: before/connect
initialization
Fri Dec 9 10:49:55 2016 : Debug: (0) >>> send TLS 1.2 [length 011e]
Fri Dec 9 10:49:55 2016 : Debug: (0) TLS_connect: unknown state
Fri Dec 9 10:49:55 2016 : Debug: (0) <<< recv TLS 1.2 [length 003e]
Fri Dec 9 10:49:55 2016 : Debug: (0) TLS_connect: SSLv3 read server hello A
Fri Dec 9 10:49:55 2016 : Debug: (0) <<< recv TLS 1.2 [length 0fb3]
Fri Dec 9 10:49:55 2016 : Debug: (0) Creating attributes from certificate
OIDs
Fri Dec 9 10:49:55 2016 : ERROR: (0) SSL says error 19 : self signed
certificate in certificate chain
Fri Dec 9 10:49:55 2016 : Debug: (0) >>> send TLS 1.2 [length 0002]
Fri Dec 9 10:49:55 2016 : ERROR: (0) TLS Alert write:fatal:unknown CA
Fri Dec 9 10:49:55 2016 : Error: tls: TLS_connect: Error in SSLv3 read
server certificate B
Fri Dec 9 10:49:55 2016 : Error: tls: TLS_connect: Error in SSLv3 read
server certificate B
Fri Dec 9 10:49:55 2016 : Error: tls: Failed in __FUNCTION__
(SSL_connect): s3_clnt.c[1186]:error:14090086:SSL
routines:SSL3_GET_SERVER_CERTIFICATE:certificate verify failed
Fri Dec 9 10:49:55 2016 : Error: tls: System call (I/O) error (-1)
Fri Dec 9 10:49:55 2016 : Error: Failed starting SSL to new proxy socket
'proxy (::, 0) -> home_server (2a03:b0c0:1:a1::a9f:8001, 2083)'
Fri Dec 9 10:49:55 2016 : Proxy: (4) Failed to insert request into the
proxy list
2
3
Hi,
I need some help to assign VLAN to users from a particular OU of Active
Directory. It does not seems to work. The code below is the post-auth in
the inner-tunnel. At the moment, the filter does not work as always get
assigned the VLAN 40.
What else should i do to get the filtering to work?. Thanks.
post-auth {
ldap
if (LDAP-Group == "OU=hod,,dc=mycompay,dc=com") {
update reply {
Tunnel-Type = VLAN
Tunnel-Medium-Type = IEEE-802
Tunnel-Private-Group-Id = "30"
}
}
else {
update reply {
Tunnel-Type = VLAN
Tunnel-Medium-Type = IEEE-802
Tunnel-Private-Group-Id = "40"
}
}
}
6
12
I'll have a quick check but sure I didn't have to do anything weird to get it working
alan
1
0
Now I did some radsec stuff in 2013 with radsecproxy but those brain cells
have long gone, and I need to use FR for this
So
As advised given up on FR 4.0
Built 2 servers running FR 3.1
Copied TLS example into /etc/freeradius/sites-enabled at both end.
Wrapped listen statement with server {...} to get it to run
Defined sending client IPv6 address at end supposed to be connecting to
Added home_server/pool/realm at sending end
Built eapol_test so I could fire an eap_peap request at the other end.
Run both serevers with
radiusd -d /etc/freeradius -fxxxx -l /var/log/radius.log>/var/log/radius.log
(yes its -fxxx because that's what it tells me to do if you want to use tls)
run eapol_test -c /usr/local/etc/sharaz-peap.conf -a 127.0.0.1 -s testing123
receiving end gets
Thu Dec 8 14:24:56 2016 : Info : Ready to process requests
Thu Dec 8 14:25:00 2016 : Debug : ... new connection request on TCP socket
Thu Dec 8 14:25:00 2016 : Debug : Listening on auth+acct from client
(2a01:348:6:59d::2, 56193) -> (::, 2083, virtual-server=sharaz-tls)
Thu Dec 8 14:25:00 2016 : Debug : tls - Closing TLS socket from client
port 56193
Thu Dec 8 14:25:00 2016 : Debug : tls - Client has closed connection
Thu Dec 8 14:25:00 2016 : Info : ... shutting down socket auth+acct from
client (2a01:348:6:59d::2, 56193) -> (::, 2083, virtual-server=sharaz-tls)
Sender seems to have
Thu Dec 8 14:41:53 2016 : Debug : No matches
Thu Dec 8 14:41:53 2016 : Info : (1) sql - Need 2 more connections
to reach min connections (3)
Thu Dec 8 14:41:53 2016 : Debug : Trying SSL to port 2083
Thu Dec 8 14:41:53 2016 : Debug : tls - Requiring Server certificate
Thu Dec 8 14:41:53 2016 : Error : tls - System call (I/O) error (0)
Thu Dec 8 14:41:53 2016 : Error : Failed starting SSL to new proxy socket
'proxy (::, 0) -> home_server (2a03:b0c0:1:a1::a9f:8001, 2083)'
Thu Dec 8 14:41:53 2016 : Proxy : (1) Failed to insert request into the
proxy list
Thu Dec 8 14:41:53 2016 : Debug : Thread 5 waiting to be assigned a request
So how do I enable enough debugging to figure out what's gone wrong at the
System Call I/O error log message point ?
2
2
Thanks for your answer.
Install freeradius 3.0.12 and iODBC.
Read docs at http://networkradius.com/doc/3.0.10
Can't understand - how work multiple sql instances in v3?
In freeradius v2 it works clear for me:
- Create in sql.conf:
sql sql_instance1 {
...
}
sql sql_instance2 {
...
}
- Use:
On virtual server1:
authorize {
sql_instance1
}
accounting {
sql_instance1
}
On virtual server2:
authorize {
sql_instance2
}
accounting {
sql_instance2
}
But in 3-d version i can't understand how it works.
Where i can find more detail info about this in v3 with examples?
2
2
08 Dec '16
Hello folks,
I am using FreeRADIUS 3.0.4 on CentOS 7.2.
In order to check the service operation of RADIUS, we are trying to
authenticate with the users file, but proxy request is made.
The setting is as follows.
- /etc/raddb/proxy.conf
realm "~^subdomain\.domain\.com$" {
authhost = LOCAL
accthost = LOCAL
}
home_server server1 {
....
}
home_server server2 {
....
}
home_server_pool server {
type = fail-over
home_server = server1
home_server = server2
}
realm DEFAULT {
pool = server
nostrip
}
- /etc/raddb/users
test(a)test.com Auth-Type := PAP , Cleartext-Password := "test"
or
test(a)test.com Auth-Type := Local , Cleartext-Password := "test"
or
test(a)test.com Cleartext-Password := "test"
...
-----
When radtest command is executed with radiusd -X, the following result
is obtained.
# radtest test(a)test.com test localhost 0 testing123
Sending Access-Request Id 3 from 0.0.0.0:48661 to 127.0.0.1:1812
User-Name = 'test(a)test.com'
User-Password = 'test'
NAS-IP-Address = X.X.X.X
NAS-Port = 0
Message-Authenticator = 0x00
Received Access-Reject Id 3 from 127.0.0.1:1812 to 127.0.0.1:48661 length 36
Reply-Message = 'Request Denied'
(0) -: Expected Access-Accept got Access-Reject
The following log is output to the console.
(snip)
(0) [auth_log] = ok
(0) [chap] = noop
(0) [mschap] = noop
(0) [digest] = noop
(0) suffix : Checking for suffix after "@"
(0) suffix : Looking up realm "test.com" for User-Name = "test(a)test.com"
(0) suffix : Found realm "DEFAULT"
(0) suffix : Adding Realm = "DEFAULT"
(0) suffix : Proxying request from user test(a)test.com to realm DEFAULT
(0) suffix : Preparing to proxy authentication request to realm "DEFAULT"
(0) [suffix] = updated
(0) eap : No EAP-Message, not doing EAP
(0) [eap] = noop
(0) files : users: Matched entry test(a)test.com at line 1
(0) [files] = ok
(0) [expiration] = noop
(0) [logintime] = noop
(0) [pap] = noop
(0) } # authorize = updated
Opening new proxy socket 'proxy address * port 0'
Listening on proxy address * port 59404
(0) Proxying request to home server X.X.X.X port 1812 timeout 30.000000
(0) Sending Access-Request packet to host X.X.X.X port 1812, id=85, length=0
(snip)
-----
My question is how to authenticate users file without
proxying ?
Best regards!
1
0