Wed Oct 14 11:06:35 2015 : Debug: Received Access-Request packet from host 10.64.76.100 port 32770, id=207, length=285 Wed Oct 14 11:06:35 2015 : Debug: User-Name = "hm6" Wed Oct 14 11:06:35 2015 : Debug: Chargeable-User-Identity = "" Wed Oct 14 11:06:35 2015 : Debug: Location-Capable = Civix-Location Wed Oct 14 11:06:35 2015 : Debug: Calling-Station-Id = "14-99-e2-bf-24-70" Wed Oct 14 11:06:35 2015 : Debug: Called-Station-Id = "00-23-eb-2e-3d-f0:Rice Owls" Wed Oct 14 11:06:35 2015 : Debug: NAS-Port = 13 Wed Oct 14 11:06:35 2015 : Debug: Cisco-AVPair = "audit-session-id=0a404c640127a12a561e621e" Wed Oct 14 11:06:35 2015 : Debug: Acct-Session-Id = "561e621e/14:99:e2:bf:24:70/10398428" Wed Oct 14 11:06:35 2015 : Debug: Cisco-AVPair = "mDNS=true" Wed Oct 14 11:06:35 2015 : Debug: NAS-IP-Address = 10.64.76.100 Wed Oct 14 11:06:35 2015 : Debug: NAS-Identifier = "WiSM2-HA1-1" Wed Oct 14 11:06:35 2015 : Debug: Airespace-Wlan-Id = 1 Wed Oct 14 11:06:35 2015 : Debug: Service-Type = Framed-User Wed Oct 14 11:06:35 2015 : Debug: Framed-MTU = 1300 Wed Oct 14 11:06:35 2015 : Debug: NAS-Port-Type = Wireless-802.11 Wed Oct 14 11:06:35 2015 : Debug: Tunnel-Type:0 = VLAN Wed Oct 14 11:06:35 2015 : Debug: Tunnel-Medium-Type:0 = IEEE-802 Wed Oct 14 11:06:35 2015 : Debug: Tunnel-Private-Group-Id:0 = "345" Wed Oct 14 11:06:35 2015 : Debug: EAP-Message = 0x0201000801686d36 Wed Oct 14 11:06:35 2015 : Debug: Message-Authenticator = 0xa29c55e08457085f2f34d996d5338aa0 Wed Oct 14 11:06:35 2015 : Debug: # Executing section authorize from file /etc/opt/freeradius/sites-enabled/default Wed Oct 14 11:06:35 2015 : Debug: +group authorize { Wed Oct 14 11:06:35 2015 : Debug: ++[preprocess] = ok Wed Oct 14 11:06:35 2015 : Debug: ++[chap] = noop Wed Oct 14 11:06:35 2015 : Debug: ++[mschap] = noop Wed Oct 14 11:06:35 2015 : Debug: ++[digest] = noop Wed Oct 14 11:06:35 2015 : Debug: [suffix] No '@' in User-Name = "hm6", looking up realm NULL Wed Oct 14 11:06:35 2015 : Debug: [suffix] Found realm "NULL" Wed Oct 14 11:06:35 2015 : Debug: [suffix] Adding Stripped-User-Name = "hm6" Wed Oct 14 11:06:35 2015 : Debug: [suffix] Adding Realm = "NULL" Wed Oct 14 11:06:35 2015 : Debug: [suffix] Authentication realm is LOCAL. Wed Oct 14 11:06:35 2015 : Debug: ++[suffix] = ok Wed Oct 14 11:06:35 2015 : Debug: ++? if (Realm =~ /wlan.*gppnetwork\.org/) Wed Oct 14 11:06:35 2015 : Debug: ? Evaluating (Realm =~ /wlan.*gppnetwork\.org/) -> FALSE Wed Oct 14 11:06:35 2015 : Debug: ++? if (Realm =~ /wlan.*gppnetwork\.org/) -> FALSE Wed Oct 14 11:06:35 2015 : Debug: ++? if (Realm == "WiFi.sktelecom.com") Wed Oct 14 11:06:35 2015 : Debug: ? Evaluating (Realm == "WiFi.sktelecom.com") -> FALSE Wed Oct 14 11:06:35 2015 : Debug: ++? if (Realm == "WiFi.sktelecom.com") -> FALSE Wed Oct 14 11:06:35 2015 : Debug: [eap] EAP packet type response id 1 length 8 Wed Oct 14 11:06:35 2015 : Debug: [eap] No EAP Start, assuming it's an on-going EAP conversation Wed Oct 14 11:06:35 2015 : Debug: ++[eap] = updated Wed Oct 14 11:06:35 2015 : Debug: ++[unix] = notfound Wed Oct 14 11:06:35 2015 : Debug: [files] users: Matched entry DEFAULT at line 92 Wed Oct 14 11:06:35 2015 : Debug: ++[files] = ok Wed Oct 14 11:06:35 2015 : Debug: ++? if (control:Auth-Type == Kerberos) Wed Oct 14 11:06:35 2015 : Debug: ? Evaluating (control:Auth-Type == Kerberos) -> FALSE Wed Oct 14 11:06:35 2015 : Debug: ++? if (control:Auth-Type == Kerberos) -> FALSE Wed Oct 14 11:06:35 2015 : Debug: ++[expiration] = noop Wed Oct 14 11:06:35 2015 : Debug: ++[logintime] = noop Wed Oct 14 11:06:35 2015 : Debug: [pap] WARNING! No "known good" password found for the user. Authentication may fail because of this. Wed Oct 14 11:06:35 2015 : Debug: ++[pap] = noop Wed Oct 14 11:06:35 2015 : Debug: +} # group authorize = updated Wed Oct 14 11:06:35 2015 : Debug: Found Auth-Type = EAP Wed Oct 14 11:06:35 2015 : Debug: # Executing group from file /etc/opt/freeradius/sites-enabled/default Wed Oct 14 11:06:35 2015 : Debug: +group authenticate { Wed Oct 14 11:06:35 2015 : Debug: [eap] EAP Identity Wed Oct 14 11:06:35 2015 : Debug: [eap] processing type tls Wed Oct 14 11:06:35 2015 : Debug: [tls] Requiring client certificate Wed Oct 14 11:06:35 2015 : Debug: [tls] Initiate Wed Oct 14 11:06:35 2015 : Debug: [tls] Start returned 1 Wed Oct 14 11:06:35 2015 : Debug: ++[eap] = handled Wed Oct 14 11:06:35 2015 : Debug: +} # group authenticate = handled Wed Oct 14 11:06:35 2015 : Debug: Sending Access-Challenge packet to host 10.64.76.100 port 32770, id=207, length=0 Wed Oct 14 11:06:35 2015 : Debug: Tunnel-Type:0 = VLAN Wed Oct 14 11:06:35 2015 : Debug: Tunnel-Medium-Type:0 = IEEE-802 Wed Oct 14 11:06:35 2015 : Debug: EAP-Message = 0x010200060d20 Wed Oct 14 11:06:35 2015 : Debug: Message-Authenticator = 0x00000000000000000000000000000000 Wed Oct 14 11:06:35 2015 : Debug: State = 0x73e0c7cb73e2caa1ed6477b7b8d8584b Wed Oct 14 11:06:35 2015 : Debug: Finished request 9057415. Wed Oct 14 11:06:35 2015 : Debug: Received Access-Request packet from host 10.64.76.100 port 32770, id=209, length=301 Wed Oct 14 11:06:35 2015 : Debug: User-Name = "hm6" Wed Oct 14 11:06:35 2015 : Debug: Chargeable-User-Identity = "" Wed Oct 14 11:06:35 2015 : Debug: Location-Capable = Civix-Location Wed Oct 14 11:06:35 2015 : Debug: Calling-Station-Id = "14-99-e2-bf-24-70" Wed Oct 14 11:06:35 2015 : Debug: Called-Station-Id = "00-23-eb-2e-3d-f0:Rice Owls" Wed Oct 14 11:06:35 2015 : Debug: NAS-Port = 13 Wed Oct 14 11:06:35 2015 : Debug: Cisco-AVPair = "audit-session-id=0a404c640127a12a561e621e" Wed Oct 14 11:06:35 2015 : Debug: Acct-Session-Id = "561e621e/14:99:e2:bf:24:70/10398428" Wed Oct 14 11:06:35 2015 : Debug: Cisco-AVPair = "mDNS=true" Wed Oct 14 11:06:35 2015 : Debug: NAS-IP-Address = 10.64.76.100 Wed Oct 14 11:06:35 2015 : Debug: NAS-Identifier = "WiSM2-HA1-1" Wed Oct 14 11:06:35 2015 : Debug: Airespace-Wlan-Id = 1 Wed Oct 14 11:06:35 2015 : Debug: Service-Type = Framed-User Wed Oct 14 11:06:35 2015 : Debug: Framed-MTU = 1300 Wed Oct 14 11:06:35 2015 : Debug: NAS-Port-Type = Wireless-802.11 Wed Oct 14 11:06:35 2015 : Debug: Tunnel-Type:0 = VLAN Wed Oct 14 11:06:35 2015 : Debug: Tunnel-Medium-Type:0 = IEEE-802 Wed Oct 14 11:06:35 2015 : Debug: Tunnel-Private-Group-Id:0 = "345" Wed Oct 14 11:06:35 2015 : Debug: EAP-Message = 0x020200060319 Wed Oct 14 11:06:35 2015 : Debug: State = 0x73e0c7cb73e2caa1ed6477b7b8d8584b Wed Oct 14 11:06:35 2015 : Debug: Message-Authenticator = 0xc9cf5b1bc7fa1852acd956b6df896e82 Wed Oct 14 11:06:35 2015 : Debug: # Executing section authorize from file /etc/opt/freeradius/sites-enabled/default Wed Oct 14 11:06:35 2015 : Debug: +group authorize { Wed Oct 14 11:06:35 2015 : Debug: ++[preprocess] = ok Wed Oct 14 11:06:35 2015 : Debug: ++[chap] = noop Wed Oct 14 11:06:35 2015 : Debug: ++[mschap] = noop Wed Oct 14 11:06:35 2015 : Debug: ++[digest] = noop Wed Oct 14 11:06:35 2015 : Debug: [suffix] No '@' in User-Name = "hm6", looking up realm NULL Wed Oct 14 11:06:35 2015 : Debug: [suffix] Found realm "NULL" Wed Oct 14 11:06:35 2015 : Debug: [suffix] Adding Stripped-User-Name = "hm6" Wed Oct 14 11:06:35 2015 : Debug: [suffix] Adding Realm = "NULL" Wed Oct 14 11:06:35 2015 : Debug: [suffix] Authentication realm is LOCAL. Wed Oct 14 11:06:35 2015 : Debug: ++[suffix] = ok Wed Oct 14 11:06:35 2015 : Debug: ++? if (Realm =~ /wlan.*gppnetwork\.org/) Wed Oct 14 11:06:35 2015 : Debug: ? Evaluating (Realm =~ /wlan.*gppnetwork\.org/) -> FALSE Wed Oct 14 11:06:35 2015 : Debug: ++? if (Realm =~ /wlan.*gppnetwork\.org/) -> FALSE Wed Oct 14 11:06:35 2015 : Debug: ++? if (Realm == "WiFi.sktelecom.com") Wed Oct 14 11:06:35 2015 : Debug: ? Evaluating (Realm == "WiFi.sktelecom.com") -> FALSE Wed Oct 14 11:06:35 2015 : Debug: ++? if (Realm == "WiFi.sktelecom.com") -> FALSE Wed Oct 14 11:06:35 2015 : Debug: [eap] EAP packet type response id 2 length 6 Wed Oct 14 11:06:35 2015 : Debug: [eap] No EAP Start, assuming it's an on-going EAP conversation Wed Oct 14 11:06:35 2015 : Debug: ++[eap] = updated Wed Oct 14 11:06:35 2015 : Debug: ++[unix] = notfound Wed Oct 14 11:06:35 2015 : Debug: [files] users: Matched entry DEFAULT at line 92 Wed Oct 14 11:06:35 2015 : Debug: ++[files] = ok Wed Oct 14 11:06:35 2015 : Debug: ++? if (control:Auth-Type == Kerberos) Wed Oct 14 11:06:35 2015 : Debug: ? Evaluating (control:Auth-Type == Kerberos) -> FALSE Wed Oct 14 11:06:35 2015 : Debug: ++? if (control:Auth-Type == Kerberos) -> FALSE Wed Oct 14 11:06:35 2015 : Debug: ++[expiration] = noop Wed Oct 14 11:06:35 2015 : Debug: ++[logintime] = noop Wed Oct 14 11:06:35 2015 : Debug: [pap] WARNING! No "known good" password found for the user. Authentication may fail because of this. Wed Oct 14 11:06:35 2015 : Debug: ++[pap] = noop Wed Oct 14 11:06:35 2015 : Debug: +} # group authorize = updated Wed Oct 14 11:06:35 2015 : Debug: Found Auth-Type = EAP Wed Oct 14 11:06:35 2015 : Debug: # Executing group from file /etc/opt/freeradius/sites-enabled/default Wed Oct 14 11:06:35 2015 : Debug: +group authenticate { Wed Oct 14 11:06:35 2015 : Debug: [eap] Request found, released from the list Wed Oct 14 11:06:35 2015 : Debug: [eap] EAP NAK Wed Oct 14 11:06:35 2015 : Debug: [eap] EAP-NAK asked for EAP-Type/peap Wed Oct 14 11:06:35 2015 : Debug: [eap] processing type tls Wed Oct 14 11:06:35 2015 : Debug: [tls] Initiate Wed Oct 14 11:06:35 2015 : Debug: [tls] Start returned 1 Wed Oct 14 11:06:35 2015 : Debug: ++[eap] = handled Wed Oct 14 11:06:35 2015 : Debug: +} # group authenticate = handled Wed Oct 14 11:06:35 2015 : Debug: Sending Access-Challenge packet to host 10.64.76.100 port 32770, id=209, length=0 Wed Oct 14 11:06:35 2015 : Debug: Tunnel-Type:0 = VLAN Wed Oct 14 11:06:35 2015 : Debug: Tunnel-Medium-Type:0 = IEEE-802 Wed Oct 14 11:06:35 2015 : Debug: EAP-Message = 0x010300061920 Wed Oct 14 11:06:35 2015 : Debug: Message-Authenticator = 0x00000000000000000000000000000000 Wed Oct 14 11:06:35 2015 : Debug: State = 0x73e0c7cb72e3dea1ed6477b7b8d8584b Wed Oct 14 11:06:35 2015 : Debug: Finished request 9057420. Wed Oct 14 11:06:35 2015 : Debug: Received Access-Request packet from host 10.64.76.100 port 32770, id=210, length=447 Wed Oct 14 11:06:35 2015 : Debug: User-Name = "hm6" Wed Oct 14 11:06:35 2015 : Debug: Chargeable-User-Identity = "" Wed Oct 14 11:06:35 2015 : Debug: Location-Capable = Civix-Location Wed Oct 14 11:06:35 2015 : Debug: Calling-Station-Id = "14-99-e2-bf-24-70" Wed Oct 14 11:06:35 2015 : Debug: Called-Station-Id = "00-23-eb-2e-3d-f0:Rice Owls" Wed Oct 14 11:06:35 2015 : Debug: NAS-Port = 13 Wed Oct 14 11:06:35 2015 : Debug: Cisco-AVPair = "audit-session-id=0a404c640127a12a561e621e" Wed Oct 14 11:06:35 2015 : Debug: Acct-Session-Id = "561e621e/14:99:e2:bf:24:70/10398428" Wed Oct 14 11:06:35 2015 : Debug: Cisco-AVPair = "mDNS=true" Wed Oct 14 11:06:35 2015 : Debug: NAS-IP-Address = 10.64.76.100 Wed Oct 14 11:06:35 2015 : Debug: NAS-Identifier = "WiSM2-HA1-1" Wed Oct 14 11:06:35 2015 : Debug: Airespace-Wlan-Id = 1 Wed Oct 14 11:06:35 2015 : Debug: Service-Type = Framed-User Wed Oct 14 11:06:35 2015 : Debug: Framed-MTU = 1300 Wed Oct 14 11:06:35 2015 : Debug: NAS-Port-Type = Wireless-802.11 Wed Oct 14 11:06:35 2015 : Debug: Tunnel-Type:0 = VLAN Wed Oct 14 11:06:35 2015 : Debug: Tunnel-Medium-Type:0 = IEEE-802 Wed Oct 14 11:06:35 2015 : Debug: Tunnel-Private-Group-Id:0 = "345" Wed Oct 14 11:06:35 2015 : Debug: EAP-Message = 0x0203009819800000008e1603010089010000850301561e7d8ceb6b159381eb964528005513132c4b913cf9958ac64937c507e9774000004a00ffc024c023c00ac009c008c028c027c014c013c012c026c025c005c004c003c02ac029c00fc00ec00d006b0067003900330016003d003c0035002f000ac007c011c002c00c0005000401000012000a00080006001700180019000b00020100 Wed Oct 14 11:06:35 2015 : Debug: State = 0x73e0c7cb72e3dea1ed6477b7b8d8584b Wed Oct 14 11:06:35 2015 : Debug: Message-Authenticator = 0x6496bde2f2c4fb94ed2a87f7fa69f30c Wed Oct 14 11:06:35 2015 : Debug: # Executing section authorize from file /etc/opt/freeradius/sites-enabled/default Wed Oct 14 11:06:35 2015 : Debug: +group authorize { Wed Oct 14 11:06:35 2015 : Debug: ++[preprocess] = ok Wed Oct 14 11:06:35 2015 : Debug: ++[chap] = noop Wed Oct 14 11:06:35 2015 : Debug: ++[mschap] = noop Wed Oct 14 11:06:35 2015 : Debug: ++[digest] = noop Wed Oct 14 11:06:35 2015 : Debug: [suffix] No '@' in User-Name = "hm6", looking up realm NULL Wed Oct 14 11:06:35 2015 : Debug: [suffix] Found realm "NULL" Wed Oct 14 11:06:35 2015 : Debug: [suffix] Adding Stripped-User-Name = "hm6" Wed Oct 14 11:06:35 2015 : Debug: [suffix] Adding Realm = "NULL" Wed Oct 14 11:06:35 2015 : Debug: [suffix] Authentication realm is LOCAL. Wed Oct 14 11:06:35 2015 : Debug: ++[suffix] = ok Wed Oct 14 11:06:35 2015 : Debug: ++? if (Realm =~ /wlan.*gppnetwork\.org/) Wed Oct 14 11:06:35 2015 : Debug: ? Evaluating (Realm =~ /wlan.*gppnetwork\.org/) -> FALSE Wed Oct 14 11:06:35 2015 : Debug: ++? if (Realm =~ /wlan.*gppnetwork\.org/) -> FALSE Wed Oct 14 11:06:35 2015 : Debug: ++? if (Realm == "WiFi.sktelecom.com") Wed Oct 14 11:06:35 2015 : Debug: ? Evaluating (Realm == "WiFi.sktelecom.com") -> FALSE Wed Oct 14 11:06:35 2015 : Debug: ++? if (Realm == "WiFi.sktelecom.com") -> FALSE Wed Oct 14 11:06:35 2015 : Debug: [eap] EAP packet type response id 3 length 152 Wed Oct 14 11:06:35 2015 : Debug: [eap] Continuing tunnel setup. Wed Oct 14 11:06:35 2015 : Debug: ++[eap] = ok Wed Oct 14 11:06:35 2015 : Debug: +} # group authorize = ok Wed Oct 14 11:06:35 2015 : Debug: Found Auth-Type = EAP Wed Oct 14 11:06:35 2015 : Debug: # Executing group from file /etc/opt/freeradius/sites-enabled/default Wed Oct 14 11:06:35 2015 : Debug: +group authenticate { Wed Oct 14 11:06:35 2015 : Debug: [eap] Request found, released from the list Wed Oct 14 11:06:35 2015 : Debug: [eap] EAP/peap Wed Oct 14 11:06:35 2015 : Debug: [eap] processing type peap Wed Oct 14 11:06:35 2015 : Debug: [peap] processing EAP-TLS Wed Oct 14 11:06:35 2015 : Debug: [peap] Length Included Wed Oct 14 11:06:35 2015 : Debug: [peap] eaptls_verify returned 11 Wed Oct 14 11:06:35 2015 : Debug: [peap] (other): before/accept initialization Wed Oct 14 11:06:35 2015 : Debug: [peap] TLS_accept: before/accept initialization Wed Oct 14 11:06:35 2015 : Debug: [peap] TLS_accept: SSLv3 read client hello A Wed Oct 14 11:06:35 2015 : Debug: [peap] TLS_accept: SSLv3 write server hello A Wed Oct 14 11:06:35 2015 : Debug: [peap] TLS_accept: SSLv3 write certificate A Wed Oct 14 11:06:35 2015 : Debug: [peap] TLS_accept: SSLv3 write key exchange A Wed Oct 14 11:06:35 2015 : Debug: [peap] TLS_accept: SSLv3 write server done A Wed Oct 14 11:06:35 2015 : Debug: [peap] TLS_accept: SSLv3 flush data Wed Oct 14 11:06:35 2015 : Debug: [peap] TLS_accept: Need to read more data: SSLv3 read client certificate A Wed Oct 14 11:06:35 2015 : Debug: [peap] TLS_accept: Need to read more data: SSLv3 read client certificate A Wed Oct 14 11:06:35 2015 : Debug: [peap] eaptls_process returned 13 Wed Oct 14 11:06:35 2015 : Debug: [peap] EAPTLS_HANDLED Wed Oct 14 11:06:35 2015 : Debug: ++[eap] = handled Wed Oct 14 11:06:35 2015 : Debug: +} # group authenticate = handled Wed Oct 14 11:06:35 2015 : Debug: Sending Access-Challenge packet to host 10.64.76.100 port 32770, id=210, length=0 Wed Oct 14 11:06:35 2015 : Debug: EAP-Message = 0x0104040019c00000127316030100510200004d0301561e7d8be4a39e0ba6cd482c0f70ec79000e3385cfbfb6217470e77130ee8d1e2018f5770292e626ce9e6943812b2252a0511c8dfe79d49224e24cb61c6a58ccc30039000005ff010001001603010efd0b000ef9000ef60005ec308205e8308204d0a003020102021100d2214325afda98a298320a313910b0a7300d06092a864886f70d01010505003051310b300906035504061302555331123010060355040a1309496e7465726e6574323111300f060355040b1308496e436f6d6d6f6e311b301906035504031312496e436f6d6d6f6e20536572766572204341301e170d3134303832353030 Wed Oct 14 11:06:35 2015 : Debug: EAP-Message = 0x303030305a170d3137303832343233353935395a3081c0310b3009060355040613025553311330110603550411130a37373235312d31383932310e300c0603550408130554657861733110300e06035504071307486f7573746f6e311430120603550409130b504f20426f782031383932310f300d060355040913064d532031313931183016060355040a130f5269636520556e6976657273697479311f301d060355040b1316496e666f726d6174696f6e20546563686e6f6c6f6779311830160603550403130f7261646975732e726963652e65647530820122300d06092a864886f70d01010105000382010f003082010a0282010100c0abafe128 Wed Oct 14 11:06:35 2015 : Debug: EAP-Message = 0x6bc30df0a3c2d2819ae89a3c0e4784956c31ce16f7845b0f72b8dd7dcc63e31b61b3943179e74feeb4f674712104b873e21b03c024c1a92c322bc112e76ce4bf126a944f32fe70e72128cbe6688c2bd64e4b97107410d77d80bf40904621d19b5977aa0a2c6ff5097aa84c4d3863032007db7ba738833594f29547be596c8989f26824bc26024146e1b678d28fb18f3d7da5a8217529d9dcc51d67d2b6b79e89363050ed5e11f5ad64167d11ae80a9c8b0bb2bcf54974c2c4ddefe3bddafeee7b0848580c750c964b05bb9700044ebc77944bfafaed6270fcba7e5fa8821b15bc62e0137f8f40f6f5caf9c1c39912617acb6ae037ef812442e4ccd0203 Wed Oct 14 11:06:35 2015 : Debug: EAP-Message = 0x010001a382024930820245301f0603551d23041830168014484f5afa2f4a9a5ee050f36b7b55a5def5be345d301d0603551d0e04160414fca71db4ce69391b700243650721246bebc46497300e0603551d0f0101ff0404030205a0300c0603551d130101ff04023000301d0603551d250416301406082b0601050507030106082b0601050507030230670603551d200460305e3052060c2b06010401ae2301040301013042304006082b06010505070201163468747470733a2f2f7777772e696e636f6d6d6f6e2e6f72672f636572742f7265706f7369746f72792f6370735f73736c2e7064663008060667810c010202303d0603551d1f0436303430 Wed Oct 14 11:06:35 2015 : Debug: EAP-Message = 0x32a030a02e862c687474703a Wed Oct 14 11:06:35 2015 : Debug: Message-Authenticator = 0x00000000000000000000000000000000 Wed Oct 14 11:06:35 2015 : Debug: State = 0x73e0c7cb71e4dea1ed6477b7b8d8584b Wed Oct 14 11:06:35 2015 : Debug: Finished request 9057421. Wed Oct 14 11:06:35 2015 : Debug: Received Access-Request packet from host 10.64.76.100 port 32770, id=211, length=301 Wed Oct 14 11:06:35 2015 : Debug: User-Name = "hm6" Wed Oct 14 11:06:35 2015 : Debug: Chargeable-User-Identity = "" Wed Oct 14 11:06:35 2015 : Debug: Location-Capable = Civix-Location Wed Oct 14 11:06:35 2015 : Debug: Calling-Station-Id = "14-99-e2-bf-24-70" Wed Oct 14 11:06:35 2015 : Debug: Called-Station-Id = "00-23-eb-2e-3d-f0:Rice Owls" Wed Oct 14 11:06:35 2015 : Debug: NAS-Port = 13 Wed Oct 14 11:06:35 2015 : Debug: Cisco-AVPair = "audit-session-id=0a404c640127a12a561e621e" Wed Oct 14 11:06:35 2015 : Debug: Acct-Session-Id = "561e621e/14:99:e2:bf:24:70/10398428" Wed Oct 14 11:06:35 2015 : Debug: Cisco-AVPair = "mDNS=true" Wed Oct 14 11:06:35 2015 : Debug: NAS-IP-Address = 10.64.76.100 Wed Oct 14 11:06:35 2015 : Debug: NAS-Identifier = "WiSM2-HA1-1" Wed Oct 14 11:06:35 2015 : Debug: Airespace-Wlan-Id = 1 Wed Oct 14 11:06:35 2015 : Debug: Service-Type = Framed-User Wed Oct 14 11:06:35 2015 : Debug: Framed-MTU = 1300 Wed Oct 14 11:06:35 2015 : Debug: NAS-Port-Type = Wireless-802.11 Wed Oct 14 11:06:35 2015 : Debug: Tunnel-Type:0 = VLAN Wed Oct 14 11:06:35 2015 : Debug: Tunnel-Medium-Type:0 = IEEE-802 Wed Oct 14 11:06:35 2015 : Debug: Tunnel-Private-Group-Id:0 = "345" Wed Oct 14 11:06:35 2015 : Debug: EAP-Message = 0x020400061900 Wed Oct 14 11:06:35 2015 : Debug: State = 0x73e0c7cb71e4dea1ed6477b7b8d8584b Wed Oct 14 11:06:35 2015 : Debug: Message-Authenticator = 0xbe167059ca1392112fa2e7920c899151 Wed Oct 14 11:06:35 2015 : Debug: # Executing section authorize from file /etc/opt/freeradius/sites-enabled/default Wed Oct 14 11:06:35 2015 : Debug: +group authorize { Wed Oct 14 11:06:35 2015 : Debug: ++[preprocess] = ok Wed Oct 14 11:06:35 2015 : Debug: ++[chap] = noop Wed Oct 14 11:06:35 2015 : Debug: ++[mschap] = noop Wed Oct 14 11:06:35 2015 : Debug: ++[digest] = noop Wed Oct 14 11:06:35 2015 : Debug: [suffix] No '@' in User-Name = "hm6", looking up realm NULL Wed Oct 14 11:06:35 2015 : Debug: [suffix] Found realm "NULL" Wed Oct 14 11:06:35 2015 : Debug: [suffix] Adding Stripped-User-Name = "hm6" Wed Oct 14 11:06:35 2015 : Debug: [suffix] Adding Realm = "NULL" Wed Oct 14 11:06:35 2015 : Debug: [suffix] Authentication realm is LOCAL. Wed Oct 14 11:06:35 2015 : Debug: ++[suffix] = ok Wed Oct 14 11:06:35 2015 : Debug: ++? if (Realm =~ /wlan.*gppnetwork\.org/) Wed Oct 14 11:06:35 2015 : Debug: ? Evaluating (Realm =~ /wlan.*gppnetwork\.org/) -> FALSE Wed Oct 14 11:06:35 2015 : Debug: ++? if (Realm =~ /wlan.*gppnetwork\.org/) -> FALSE Wed Oct 14 11:06:35 2015 : Debug: ++? if (Realm == "WiFi.sktelecom.com") Wed Oct 14 11:06:35 2015 : Debug: ? Evaluating (Realm == "WiFi.sktelecom.com") -> FALSE Wed Oct 14 11:06:35 2015 : Debug: ++? if (Realm == "WiFi.sktelecom.com") -> FALSE Wed Oct 14 11:06:35 2015 : Debug: [eap] EAP packet type response id 4 length 6 Wed Oct 14 11:06:35 2015 : Debug: [eap] Continuing tunnel setup. Wed Oct 14 11:06:35 2015 : Debug: ++[eap] = ok Wed Oct 14 11:06:35 2015 : Debug: +} # group authorize = ok Wed Oct 14 11:06:35 2015 : Debug: Found Auth-Type = EAP Wed Oct 14 11:06:35 2015 : Debug: # Executing group from file /etc/opt/freeradius/sites-enabled/default Wed Oct 14 11:06:35 2015 : Debug: +group authenticate { Wed Oct 14 11:06:35 2015 : Debug: [eap] Request found, released from the list Wed Oct 14 11:06:35 2015 : Debug: [eap] EAP/peap Wed Oct 14 11:06:35 2015 : Debug: [eap] processing type peap Wed Oct 14 11:06:35 2015 : Debug: [peap] processing EAP-TLS Wed Oct 14 11:06:35 2015 : Debug: [peap] Received TLS ACK Wed Oct 14 11:06:35 2015 : Debug: [peap] ACK handshake fragment handler Wed Oct 14 11:06:35 2015 : Debug: [peap] eaptls_verify returned 1 Wed Oct 14 11:06:35 2015 : Debug: [peap] eaptls_process returned 13 Wed Oct 14 11:06:35 2015 : Debug: [peap] EAPTLS_HANDLED Wed Oct 14 11:06:35 2015 : Debug: ++[eap] = handled Wed Oct 14 11:06:35 2015 : Debug: +} # group authenticate = handled Wed Oct 14 11:06:35 2015 : Debug: Sending Access-Challenge packet to host 10.64.76.100 port 32770, id=211, length=0 Wed Oct 14 11:06:35 2015 : Debug: EAP-Message = 0x010503fc19402f2f63726c2e696e636f6d6d6f6e2e6f72672f496e436f6d6d6f6e53657276657243412e63726c306f06082b0601050507010104633061303906082b06010505073002862d687474703a2f2f636572742e696e636f6d6d6f6e2e6f72672f496e436f6d6d6f6e53657276657243412e637274302406082b060105050730018618687474703a2f2f6f6373702e696e636f6d6d6f6e2e6f72673081ac0603551d110481a43081a1820f7261646975732e726963652e65647582186e65777261646975732d612e6e65742e726963652e65647582186e65777261646975732d622e6e65742e726963652e65647582157261646975732d612e6e Wed Oct 14 11:06:35 2015 : Debug: EAP-Message = 0x65742e726963652e65647582157261646975732d622e6e65742e726963652e65647582157261646975732d632e6e65742e726963652e65647582157261646975732d642e6e65742e726963652e656475300d06092a864886f70d0101050500038201010024b8ca39f8c5c7f30b29b43b46d5a205a13cff521c12aa709dba4a38b2db77d20a727adcf7a1f9fbb14ba8ef4b42ff5a17d4a50afa0539284f32566b1aa6c4ce179ccaeb57849e15465a592e9a6687ea84ba8cfece9d5480911b6b1bf0e539707e8e47951fbb90dbcdce93548fa1a8a2e36444b878c84fbe52740039e794686cd81d29ac09fcb9fc397d5b5c47b4904dd54640d8709c42a9dd Wed Oct 14 11:06:35 2015 : Debug: EAP-Message = 0x051695e9dfc9123a2f34881eb6888ff944bb0711cff3ea080287dbdd52811c91ea341f310e1ff2bd196b946d47264ec297d29eb65dba202b4309df303a2b8b80393aea3e914d7adfc9ad596a26d3866f221ef17e0db57a0573481457393ecd678788ce4afa12360004c7308204c3308203aba00302010202107f71c1d3a226b0d2b113f3e68167643e300d06092a864886f70d0101050500306f310b300906035504061302534531143012060355040a130b416464547275737420414231263024060355040b131d41646454727573742045787465726e616c20545450204e6574776f726b312230200603550403131941646454727573742045787465 Wed Oct 14 11:06:35 2015 : Debug: EAP-Message = 0x726e616c20434120526f6f74301e170d3130313230373030303030305a170d3230303533303130343833385a3051310b300906035504061302555331123010060355040a1309496e7465726e6574323111300f060355040b1308496e436f6d6d6f6e311b301906035504031312496e436f6d6d6f6e2053657276657220434130820122300d06092a864886f70d01010105000382010f003082010a0282010100977cc7c8feb3e9206aa3a44f8e8e345606b37a6caa109b48612b369069e3340a47a7bb7bdeaa6afbeb82958fca1d7faf75a6a84cda2067611a0d86c1cac187afac4ee4de621b2f9db198afc601fb1770dbac1459ec6f3f337fa6980be4 Wed Oct 14 11:06:35 2015 : Debug: EAP-Message = 0xe238aff57f856d0e Wed Oct 14 11:06:35 2015 : Debug: Message-Authenticator = 0x00000000000000000000000000000000 Wed Oct 14 11:06:35 2015 : Debug: State = 0x73e0c7cb70e5dea1ed6477b7b8d8584b Wed Oct 14 11:06:35 2015 : Debug: Finished request 9057422. Wed Oct 14 11:06:35 2015 : Debug: Received Access-Request packet from host 10.64.76.100 port 32770, id=213, length=301 Wed Oct 14 11:06:35 2015 : Debug: User-Name = "hm6" Wed Oct 14 11:06:35 2015 : Debug: Chargeable-User-Identity = "" Wed Oct 14 11:06:35 2015 : Debug: Location-Capable = Civix-Location Wed Oct 14 11:06:35 2015 : Debug: Calling-Station-Id = "14-99-e2-bf-24-70" Wed Oct 14 11:06:35 2015 : Debug: Called-Station-Id = "00-23-eb-2e-3d-f0:Rice Owls" Wed Oct 14 11:06:35 2015 : Debug: NAS-Port = 13 Wed Oct 14 11:06:35 2015 : Debug: Cisco-AVPair = "audit-session-id=0a404c640127a12a561e621e" Wed Oct 14 11:06:35 2015 : Debug: Acct-Session-Id = "561e621e/14:99:e2:bf:24:70/10398428" Wed Oct 14 11:06:35 2015 : Debug: Cisco-AVPair = "mDNS=true" Wed Oct 14 11:06:35 2015 : Debug: NAS-IP-Address = 10.64.76.100 Wed Oct 14 11:06:35 2015 : Debug: NAS-Identifier = "WiSM2-HA1-1" Wed Oct 14 11:06:35 2015 : Debug: Airespace-Wlan-Id = 1 Wed Oct 14 11:06:35 2015 : Debug: Service-Type = Framed-User Wed Oct 14 11:06:35 2015 : Debug: Framed-MTU = 1300 Wed Oct 14 11:06:35 2015 : Debug: NAS-Port-Type = Wireless-802.11 Wed Oct 14 11:06:35 2015 : Debug: Tunnel-Type:0 = VLAN Wed Oct 14 11:06:35 2015 : Debug: Tunnel-Medium-Type:0 = IEEE-802 Wed Oct 14 11:06:35 2015 : Debug: Tunnel-Private-Group-Id:0 = "345" Wed Oct 14 11:06:35 2015 : Debug: EAP-Message = 0x020500061900 Wed Oct 14 11:06:35 2015 : Debug: State = 0x73e0c7cb70e5dea1ed6477b7b8d8584b Wed Oct 14 11:06:35 2015 : Debug: Message-Authenticator = 0x65b8bc2b9f221054fd434b23d071df41 Wed Oct 14 11:06:35 2015 : Debug: # Executing section authorize from file /etc/opt/freeradius/sites-enabled/default Wed Oct 14 11:06:35 2015 : Debug: +group authorize { Wed Oct 14 11:06:35 2015 : Debug: ++[preprocess] = ok Wed Oct 14 11:06:35 2015 : Debug: ++[chap] = noop Wed Oct 14 11:06:35 2015 : Debug: ++[mschap] = noop Wed Oct 14 11:06:35 2015 : Debug: ++[digest] = noop Wed Oct 14 11:06:35 2015 : Debug: [suffix] No '@' in User-Name = "hm6", looking up realm NULL Wed Oct 14 11:06:35 2015 : Debug: [suffix] Found realm "NULL" Wed Oct 14 11:06:35 2015 : Debug: [suffix] Adding Stripped-User-Name = "hm6" Wed Oct 14 11:06:35 2015 : Debug: [suffix] Adding Realm = "NULL" Wed Oct 14 11:06:35 2015 : Debug: [suffix] Authentication realm is LOCAL. Wed Oct 14 11:06:35 2015 : Debug: ++[suffix] = ok Wed Oct 14 11:06:35 2015 : Debug: ++? if (Realm =~ /wlan.*gppnetwork\.org/) Wed Oct 14 11:06:35 2015 : Debug: ? Evaluating (Realm =~ /wlan.*gppnetwork\.org/) -> FALSE Wed Oct 14 11:06:35 2015 : Debug: ++? if (Realm =~ /wlan.*gppnetwork\.org/) -> FALSE Wed Oct 14 11:06:35 2015 : Debug: ++? if (Realm == "WiFi.sktelecom.com") Wed Oct 14 11:06:35 2015 : Debug: ? Evaluating (Realm == "WiFi.sktelecom.com") -> FALSE Wed Oct 14 11:06:35 2015 : Debug: ++? if (Realm == "WiFi.sktelecom.com") -> FALSE Wed Oct 14 11:06:35 2015 : Debug: [eap] EAP packet type response id 5 length 6 Wed Oct 14 11:06:35 2015 : Debug: [eap] Continuing tunnel setup. Wed Oct 14 11:06:35 2015 : Debug: ++[eap] = ok Wed Oct 14 11:06:35 2015 : Debug: +} # group authorize = ok Wed Oct 14 11:06:35 2015 : Debug: Found Auth-Type = EAP Wed Oct 14 11:06:35 2015 : Debug: # Executing group from file /etc/opt/freeradius/sites-enabled/default Wed Oct 14 11:06:35 2015 : Debug: +group authenticate { Wed Oct 14 11:06:35 2015 : Debug: [eap] Request found, released from the list Wed Oct 14 11:06:35 2015 : Debug: [eap] EAP/peap Wed Oct 14 11:06:35 2015 : Debug: [eap] processing type peap Wed Oct 14 11:06:35 2015 : Debug: [peap] processing EAP-TLS Wed Oct 14 11:06:35 2015 : Debug: [peap] Received TLS ACK Wed Oct 14 11:06:35 2015 : Debug: [peap] ACK handshake fragment handler Wed Oct 14 11:06:35 2015 : Debug: [peap] eaptls_verify returned 1 Wed Oct 14 11:06:35 2015 : Debug: [peap] eaptls_process returned 13 Wed Oct 14 11:06:35 2015 : Debug: [peap] EAPTLS_HANDLED Wed Oct 14 11:06:35 2015 : Debug: ++[eap] = handled Wed Oct 14 11:06:35 2015 : Debug: +} # group authenticate = handled Wed Oct 14 11:06:35 2015 : Debug: Sending Access-Challenge packet to host 10.64.76.100 port 32770, id=213, length=0 Wed Oct 14 11:06:35 2015 : Debug: EAP-Message = 0x010603fc194074049df62786c79b8fe7712a08f403024063247d40578f54e0547eb6134861f1dece0ebdb6fa4d98b2d90d8d79a6e0aacd0c919aa5dfab73bbca14785c4729a1cac5ba9fc7da60f7ffe77ff2d9daa12d0f4916a7d30092cf8a47d94df8d59566d374f98063004f4c84161fb3f5241fa14edee895d6b20b098b2c6bc75c2f8c63c999cb52b1627b7301627f636cd868a0ee6aa88d1f29f3d018acad0203010001a382017730820173301f0603551d23041830168014adbd987a34b426f7fac42654ef03bde024cb541a301d0603551d0e04160414484f5afa2f4a9a5ee050f36b7b55a5def5be345d300e0603551d0f0101ff0404030201 Wed Oct 14 11:06:35 2015 : Debug: EAP-Message = 0x0630120603551d130101ff040830060101ff02010030110603551d20040a300830060604551d200030440603551d1f043d303b3039a037a0358633687474703a2f2f63726c2e7573657274727573742e636f6d2f416464547275737445787465726e616c4341526f6f742e63726c3081b306082b060105050701010481a63081a3303f06082b060105050730028633687474703a2f2f6372742e7573657274727573742e636f6d2f416464547275737445787465726e616c4341526f6f742e703763303906082b06010505073002862d687474703a2f2f6372742e7573657274727573742e636f6d2f416464547275737455544e53474343412e637274 Wed Oct 14 11:06:35 2015 : Debug: EAP-Message = 0x302506082b060105050730018619687474703a2f2f6f6373702e7573657274727573742e636f6d300d06092a864886f70d01010505000382010100936621807445854bc2abce32b029fedddfd6245bbf036a6f503e0e1bb30d88a35beec4a4123b56ef067fcf7f2195563b4131fee1aa93d295f3950d3c47abca5c26ad3ef1f98c346e11bef467e30249f9a67c7b6425dd1746f250e3e30a213a4924cdc68465686768b0452d4799cd9cab86291172dcd69c364374f3d4979e56a0fe5f4058d2d5d77e7cc58e1ab2045c92660e85ad2e06cec8a3d8eb142791decf17308153b66612ad37e4f5ef965c200e36e9ac627d19818af59061a649abce3cdfe6 Wed Oct 14 11:06:35 2015 : Debug: EAP-Message = 0xca64ee826539459516ba41060098ba0c5661e4c6c68601cf66a9222902d63dcfc42a8d99defb09149e0ed1d5c6d781ddad24abac0705e21d68c370665fd300043a308204363082031ea003020102020101300d06092a864886f70d0101050500306f310b300906035504061302534531143012060355040a130b416464547275737420414231263024060355040b131d41646454727573742045787465726e616c20545450204e6574776f726b312230200603550403131941646454727573742045787465726e616c20434120526f6f74301e170d3030303533303130343833385a170d3230303533303130343833385a306f310b3009060355040613 Wed Oct 14 11:06:35 2015 : Debug: EAP-Message = 0x0253453114301206 Wed Oct 14 11:06:35 2015 : Debug: Message-Authenticator = 0x00000000000000000000000000000000 Wed Oct 14 11:06:35 2015 : Debug: State = 0x73e0c7cb77e6dea1ed6477b7b8d8584b Wed Oct 14 11:06:35 2015 : Debug: Finished request 9057425. Wed Oct 14 11:06:35 2015 : Debug: Received Access-Request packet from host 10.64.76.100 port 32770, id=216, length=301 Wed Oct 14 11:06:35 2015 : Debug: User-Name = "hm6" Wed Oct 14 11:06:35 2015 : Debug: Chargeable-User-Identity = "" Wed Oct 14 11:06:35 2015 : Debug: Location-Capable = Civix-Location Wed Oct 14 11:06:35 2015 : Debug: Calling-Station-Id = "14-99-e2-bf-24-70" Wed Oct 14 11:06:35 2015 : Debug: Called-Station-Id = "00-23-eb-2e-3d-f0:Rice Owls" Wed Oct 14 11:06:35 2015 : Debug: NAS-Port = 13 Wed Oct 14 11:06:35 2015 : Debug: Cisco-AVPair = "audit-session-id=0a404c640127a12a561e621e" Wed Oct 14 11:06:35 2015 : Debug: Acct-Session-Id = "561e621e/14:99:e2:bf:24:70/10398428" Wed Oct 14 11:06:35 2015 : Debug: Cisco-AVPair = "mDNS=true" Wed Oct 14 11:06:35 2015 : Debug: NAS-IP-Address = 10.64.76.100 Wed Oct 14 11:06:35 2015 : Debug: NAS-Identifier = "WiSM2-HA1-1" Wed Oct 14 11:06:35 2015 : Debug: Airespace-Wlan-Id = 1 Wed Oct 14 11:06:35 2015 : Debug: Service-Type = Framed-User Wed Oct 14 11:06:35 2015 : Debug: Framed-MTU = 1300 Wed Oct 14 11:06:35 2015 : Debug: NAS-Port-Type = Wireless-802.11 Wed Oct 14 11:06:35 2015 : Debug: Tunnel-Type:0 = VLAN Wed Oct 14 11:06:35 2015 : Debug: Tunnel-Medium-Type:0 = IEEE-802 Wed Oct 14 11:06:35 2015 : Debug: Tunnel-Private-Group-Id:0 = "345" Wed Oct 14 11:06:35 2015 : Debug: EAP-Message = 0x020600061900 Wed Oct 14 11:06:35 2015 : Debug: State = 0x73e0c7cb77e6dea1ed6477b7b8d8584b Wed Oct 14 11:06:35 2015 : Debug: Message-Authenticator = 0xf5dd9a6b00f45e88a716beb498941a1d Wed Oct 14 11:06:35 2015 : Debug: # Executing section authorize from file /etc/opt/freeradius/sites-enabled/default Wed Oct 14 11:06:35 2015 : Debug: +group authorize { Wed Oct 14 11:06:35 2015 : Debug: ++[preprocess] = ok Wed Oct 14 11:06:35 2015 : Debug: ++[chap] = noop Wed Oct 14 11:06:35 2015 : Debug: ++[mschap] = noop Wed Oct 14 11:06:35 2015 : Debug: ++[digest] = noop Wed Oct 14 11:06:35 2015 : Debug: [suffix] No '@' in User-Name = "hm6", looking up realm NULL Wed Oct 14 11:06:35 2015 : Debug: [suffix] Found realm "NULL" Wed Oct 14 11:06:35 2015 : Debug: [suffix] Adding Stripped-User-Name = "hm6" Wed Oct 14 11:06:35 2015 : Debug: [suffix] Adding Realm = "NULL" Wed Oct 14 11:06:35 2015 : Debug: [suffix] Authentication realm is LOCAL. Wed Oct 14 11:06:35 2015 : Debug: ++[suffix] = ok Wed Oct 14 11:06:35 2015 : Debug: ++? if (Realm =~ /wlan.*gppnetwork\.org/) Wed Oct 14 11:06:35 2015 : Debug: ? Evaluating (Realm =~ /wlan.*gppnetwork\.org/) -> FALSE Wed Oct 14 11:06:35 2015 : Debug: ++? if (Realm =~ /wlan.*gppnetwork\.org/) -> FALSE Wed Oct 14 11:06:35 2015 : Debug: ++? if (Realm == "WiFi.sktelecom.com") Wed Oct 14 11:06:35 2015 : Debug: ? Evaluating (Realm == "WiFi.sktelecom.com") -> FALSE Wed Oct 14 11:06:35 2015 : Debug: ++? if (Realm == "WiFi.sktelecom.com") -> FALSE Wed Oct 14 11:06:35 2015 : Debug: [eap] EAP packet type response id 6 length 6 Wed Oct 14 11:06:35 2015 : Debug: [eap] Continuing tunnel setup. Wed Oct 14 11:06:35 2015 : Debug: ++[eap] = ok Wed Oct 14 11:06:35 2015 : Debug: +} # group authorize = ok Wed Oct 14 11:06:35 2015 : Debug: Found Auth-Type = EAP Wed Oct 14 11:06:35 2015 : Debug: # Executing group from file /etc/opt/freeradius/sites-enabled/default Wed Oct 14 11:06:35 2015 : Debug: +group authenticate { Wed Oct 14 11:06:35 2015 : Debug: [eap] Request found, released from the list Wed Oct 14 11:06:35 2015 : Debug: [eap] EAP/peap Wed Oct 14 11:06:35 2015 : Debug: [eap] processing type peap Wed Oct 14 11:06:35 2015 : Debug: [peap] processing EAP-TLS Wed Oct 14 11:06:35 2015 : Debug: [peap] Received TLS ACK Wed Oct 14 11:06:35 2015 : Debug: [peap] ACK handshake fragment handler Wed Oct 14 11:06:35 2015 : Debug: [peap] eaptls_verify returned 1 Wed Oct 14 11:06:35 2015 : Debug: [peap] eaptls_process returned 13 Wed Oct 14 11:06:35 2015 : Debug: [peap] EAPTLS_HANDLED Wed Oct 14 11:06:35 2015 : Debug: ++[eap] = handled Wed Oct 14 11:06:35 2015 : Debug: +} # group authenticate = handled Wed Oct 14 11:06:35 2015 : Debug: Sending Access-Challenge packet to host 10.64.76.100 port 32770, id=216, length=0 Wed Oct 14 11:06:35 2015 : Debug: EAP-Message = 0x010703fc19400355040a130b416464547275737420414231263024060355040b131d41646454727573742045787465726e616c20545450204e6574776f726b312230200603550403131941646454727573742045787465726e616c20434120526f6f7430820122300d06092a864886f70d01010105000382010f003082010a0282010100b7f71a33e6f200042d39e04e5bed1fbc6c0fcdb5fa23b6cede9b113397a4294c7d939fbd4abc93ed031ae38fcfe56d505ad69729945a80b0497adb2e95fdb8cabf37382d1e3e9141ad7056c7f04f3fe8329e74cac89054e9c65f0f789d9a403c0eac61aa5e148f9e87a16a50dcd79a4eaf05b3a671949c71b3 Wed Oct 14 11:06:35 2015 : Debug: EAP-Message = 0x50600ac7139d38078602a8e9a869261890ab4cb04f23ab3a4f84d8dfce9fe1696fbbd742d76b44e4c7adee6d415f725a710837b37965a459a09437f7002f0dc29272dad03872db14a845c45d2a7db7b4d6c4eeaccd1344b7c92bdd430025fa61b9696a582311b7a7338f567559f5cd29d746b70a2b65b6d3426f15b2b87bfbefe95d53d5345a270203010001a381dc3081d9301d0603551d0e04160414adbd987a34b426f7fac42654ef03bde024cb541a300b0603551d0f040403020106300f0603551d130101ff040530030101ff3081990603551d2304819130818e8014adbd987a34b426f7fac42654ef03bde024cb541aa173a471306f310b3009 Wed Oct 14 11:06:35 2015 : Debug: EAP-Message = 0x06035504061302534531143012060355040a130b416464547275737420414231263024060355040b131d41646454727573742045787465726e616c20545450204e6574776f726b312230200603550403131941646454727573742045787465726e616c20434120526f6f74820101300d06092a864886f70d01010505000382010100b09be08525c2d623e20f9606929d41989cd9847981d91e5b14072336658fb0d877bbac416c47608351b0f9323de7fcf62613c78016a5bf5afc87cf787989219ae24c070a8635bcf2de51c4d296b7dc7e4eee70fd1c39eb0c0251142d8ebd16e0c1df4675e724adecf442b48593701067ba9d06354a18d32b7acc51 Wed Oct 14 11:06:35 2015 : Debug: EAP-Message = 0x42a17a63d1e6bba1c52bc236be130de6bd637e797ba7090d40ab6add8f8ac3f6f68c1a420551d445f59fa76221681520433c99e77cbd24d8a9911773883f561b313818b4710f9acdc80e9e8e2e1be18c9883cb1f31f1444cc604734976600fc7f8bd17806b2ee9cc4c0e5a9a790f200a2ed59e63261e559294d882175a7bd0bcc78f4e8604160301030d0c0003090100ed62d54d0d16abdddbf775ef679af503cb1dcb2a0e46890f9335b92cfd62fcb5aeea94a4b269f6e2d87adfe9076ba5cdf9b4f0e4c3ad531cacb4aa5d94c732ba343ac7d6a70dee7681cc09cce6d387654dff6253af216b50c936e995074eabff87a53fe2b3d4f6fadf6440f821 Wed Oct 14 11:06:35 2015 : Debug: EAP-Message = 0x0c7d10e0f13cd6eb Wed Oct 14 11:06:35 2015 : Debug: Message-Authenticator = 0x00000000000000000000000000000000 Wed Oct 14 11:06:35 2015 : Debug: State = 0x73e0c7cb76e7dea1ed6477b7b8d8584b Wed Oct 14 11:06:35 2015 : Debug: Finished request 9057429. Wed Oct 14 11:06:35 2015 : Debug: Received Access-Request packet from host 10.64.76.100 port 32770, id=218, length=301 Wed Oct 14 11:06:35 2015 : Debug: User-Name = "hm6" Wed Oct 14 11:06:35 2015 : Debug: Chargeable-User-Identity = "" Wed Oct 14 11:06:35 2015 : Debug: Location-Capable = Civix-Location Wed Oct 14 11:06:35 2015 : Debug: Calling-Station-Id = "14-99-e2-bf-24-70" Wed Oct 14 11:06:35 2015 : Debug: Called-Station-Id = "00-23-eb-2e-3d-f0:Rice Owls" Wed Oct 14 11:06:35 2015 : Debug: NAS-Port = 13 Wed Oct 14 11:06:35 2015 : Debug: Cisco-AVPair = "audit-session-id=0a404c640127a12a561e621e" Wed Oct 14 11:06:35 2015 : Debug: Acct-Session-Id = "561e621e/14:99:e2:bf:24:70/10398428" Wed Oct 14 11:06:35 2015 : Debug: Cisco-AVPair = "mDNS=true" Wed Oct 14 11:06:35 2015 : Debug: NAS-IP-Address = 10.64.76.100 Wed Oct 14 11:06:35 2015 : Debug: NAS-Identifier = "WiSM2-HA1-1" Wed Oct 14 11:06:35 2015 : Debug: Airespace-Wlan-Id = 1 Wed Oct 14 11:06:35 2015 : Debug: Service-Type = Framed-User Wed Oct 14 11:06:35 2015 : Debug: Framed-MTU = 1300 Wed Oct 14 11:06:35 2015 : Debug: NAS-Port-Type = Wireless-802.11 Wed Oct 14 11:06:35 2015 : Debug: Tunnel-Type:0 = VLAN Wed Oct 14 11:06:35 2015 : Debug: Tunnel-Medium-Type:0 = IEEE-802 Wed Oct 14 11:06:35 2015 : Debug: Tunnel-Private-Group-Id:0 = "345" Wed Oct 14 11:06:35 2015 : Debug: EAP-Message = 0x020700061900 Wed Oct 14 11:06:35 2015 : Debug: State = 0x73e0c7cb76e7dea1ed6477b7b8d8584b Wed Oct 14 11:06:35 2015 : Debug: Message-Authenticator = 0x9b176e9332770f69134f7b7ed457ee15 Wed Oct 14 11:06:35 2015 : Debug: # Executing section authorize from file /etc/opt/freeradius/sites-enabled/default Wed Oct 14 11:06:35 2015 : Debug: +group authorize { Wed Oct 14 11:06:35 2015 : Debug: ++[preprocess] = ok Wed Oct 14 11:06:35 2015 : Debug: ++[chap] = noop Wed Oct 14 11:06:35 2015 : Debug: ++[mschap] = noop Wed Oct 14 11:06:35 2015 : Debug: ++[digest] = noop Wed Oct 14 11:06:35 2015 : Debug: [suffix] No '@' in User-Name = "hm6", looking up realm NULL Wed Oct 14 11:06:35 2015 : Debug: [suffix] Found realm "NULL" Wed Oct 14 11:06:35 2015 : Debug: [suffix] Adding Stripped-User-Name = "hm6" Wed Oct 14 11:06:35 2015 : Debug: [suffix] Adding Realm = "NULL" Wed Oct 14 11:06:35 2015 : Debug: [suffix] Authentication realm is LOCAL. Wed Oct 14 11:06:35 2015 : Debug: ++[suffix] = ok Wed Oct 14 11:06:35 2015 : Debug: ++? if (Realm =~ /wlan.*gppnetwork\.org/) Wed Oct 14 11:06:35 2015 : Debug: ? Evaluating (Realm =~ /wlan.*gppnetwork\.org/) -> FALSE Wed Oct 14 11:06:35 2015 : Debug: ++? if (Realm =~ /wlan.*gppnetwork\.org/) -> FALSE Wed Oct 14 11:06:35 2015 : Debug: ++? if (Realm == "WiFi.sktelecom.com") Wed Oct 14 11:06:35 2015 : Debug: ? Evaluating (Realm == "WiFi.sktelecom.com") -> FALSE Wed Oct 14 11:06:35 2015 : Debug: ++? if (Realm == "WiFi.sktelecom.com") -> FALSE Wed Oct 14 11:06:35 2015 : Debug: [eap] EAP packet type response id 7 length 6 Wed Oct 14 11:06:35 2015 : Debug: [eap] Continuing tunnel setup. Wed Oct 14 11:06:35 2015 : Debug: ++[eap] = ok Wed Oct 14 11:06:35 2015 : Debug: +} # group authorize = ok Wed Oct 14 11:06:35 2015 : Debug: Found Auth-Type = EAP Wed Oct 14 11:06:35 2015 : Debug: # Executing group from file /etc/opt/freeradius/sites-enabled/default Wed Oct 14 11:06:35 2015 : Debug: +group authenticate { Wed Oct 14 11:06:35 2015 : Debug: [eap] Request found, released from the list Wed Oct 14 11:06:35 2015 : Debug: [eap] EAP/peap Wed Oct 14 11:06:35 2015 : Debug: [eap] processing type peap Wed Oct 14 11:06:35 2015 : Debug: [peap] processing EAP-TLS Wed Oct 14 11:06:35 2015 : Debug: [peap] Received TLS ACK Wed Oct 14 11:06:35 2015 : Debug: [peap] ACK handshake fragment handler Wed Oct 14 11:06:35 2015 : Debug: [peap] eaptls_verify returned 1 Wed Oct 14 11:06:35 2015 : Debug: [peap] eaptls_process returned 13 Wed Oct 14 11:06:35 2015 : Debug: [peap] EAPTLS_HANDLED Wed Oct 14 11:06:35 2015 : Debug: ++[eap] = handled Wed Oct 14 11:06:35 2015 : Debug: +} # group authenticate = handled Wed Oct 14 11:06:35 2015 : Debug: Sending Access-Challenge packet to host 10.64.76.100 port 32770, id=218, length=0 Wed Oct 14 11:06:35 2015 : Debug: EAP-Message = 0x010802a11900235117f28a47b4795ecfe8c241d8cb16a3fbb155ef7bc9fe89f4db168e1771802cbb8cc407db26e80f26a0d6f603d389871936a47ad44c832a1f434a0dce681e4776baedd455ff6ab46be0e18bd0fdc968d099cc7bf196177a0528bc3fb3421c5c7e0a6750ed98c25168379f2d6072df0e479af6b79986830f9df1d233c20646276bcdc8f76bc0646774db0001020100a50d494e8b203e36ac82a8e7cc5719fd9b2f38c73a7beeb1ff1fc16765a393b35de612abd209c1013ec4cf5db0840438ded55835120e3f16fae7bd9508f5bca865de9055229a00e2c494fa185590cff47b35b2f95ae77dcf65301500fa67850726dedc6283ea0e Wed Oct 14 11:06:35 2015 : Debug: EAP-Message = 0xb4ba67015bedf84a0166cef4a7f0090a3d73535e17d816de399da68c21801db816421fb3a41ac823e404482a214b09386ebfd230a73f298d0fc409c645f0d920962ab0998fe92c44dff5fa83811c82c0888978d9c86382cee4774f7bf5e2ad3279d6fba6592d4ad1d7b586aebf2ad60b59ab8ca72a9d167c0a9be03f7a26f8c954ad78fc7b34da830adce58f3f8836e9a66790a243373c1991010089d57ddefc37cb6deabd5364db65d79b26b0e84264d7f3b9778c067d4d495301d288e2ae6df7a39915933fdcc674d1fd2a607d0a7ae91b6ec54df3b279405c71e6bd7ef4d3a75b155f9fcc39e96c7d7bb3cf299118f1b60d446c023c643b24593056 Wed Oct 14 11:06:35 2015 : Debug: EAP-Message = 0x4fd534b7852fcfd2ebb32b1339ad958705aec660590775119d368d39c688431f54104a5f41ed4224993f16b55467117386436b4dcb0856877d3e0065556b1507177b838947d27a555e0233ba7924d6d067f31113959dcaf97f23a621f1135054aa48aac08a7f4836c430300dd44aff813611bfa2a2543a10a57449cf52163ca3605aabc986a9c12e2950c834a4034b9d79532426f43e5a5a2cb63550e13416030100040e000000 Wed Oct 14 11:06:35 2015 : Debug: Message-Authenticator = 0x00000000000000000000000000000000 Wed Oct 14 11:06:35 2015 : Debug: State = 0x73e0c7cb75e8dea1ed6477b7b8d8584b Wed Oct 14 11:06:35 2015 : Debug: Finished request 9057431. Wed Oct 14 11:06:35 2015 : Debug: Received Access-Request packet from host 10.64.76.100 port 32770, id=242, length=633 Wed Oct 14 11:06:35 2015 : Debug: User-Name = "hm6" Wed Oct 14 11:06:35 2015 : Debug: Chargeable-User-Identity = "" Wed Oct 14 11:06:35 2015 : Debug: Location-Capable = Civix-Location Wed Oct 14 11:06:35 2015 : Debug: Calling-Station-Id = "14-99-e2-bf-24-70" Wed Oct 14 11:06:35 2015 : Debug: Called-Station-Id = "00-23-eb-2e-3d-f0:Rice Owls" Wed Oct 14 11:06:35 2015 : Debug: NAS-Port = 13 Wed Oct 14 11:06:35 2015 : Debug: Cisco-AVPair = "audit-session-id=0a404c640127a12a561e621e" Wed Oct 14 11:06:35 2015 : Debug: Acct-Session-Id = "561e621e/14:99:e2:bf:24:70/10398428" Wed Oct 14 11:06:35 2015 : Debug: Cisco-AVPair = "mDNS=true" Wed Oct 14 11:06:35 2015 : Debug: NAS-IP-Address = 10.64.76.100 Wed Oct 14 11:06:35 2015 : Debug: NAS-Identifier = "WiSM2-HA1-1" Wed Oct 14 11:06:35 2015 : Debug: Airespace-Wlan-Id = 1 Wed Oct 14 11:06:35 2015 : Debug: Service-Type = Framed-User Wed Oct 14 11:06:35 2015 : Debug: Framed-MTU = 1300 Wed Oct 14 11:06:35 2015 : Debug: NAS-Port-Type = Wireless-802.11 Wed Oct 14 11:06:35 2015 : Debug: Tunnel-Type:0 = VLAN Wed Oct 14 11:06:35 2015 : Debug: Tunnel-Medium-Type:0 = IEEE-802 Wed Oct 14 11:06:35 2015 : Debug: Tunnel-Private-Group-Id:0 = "345" Wed Oct 14 11:06:35 2015 : Debug: EAP-Message = 0x0208015019800000014616030101061000010201003ce2e6ab8ba7bbcf40053c71323c7ad52028a669d8b35e005ffa84f08697d90cb999af9f4dd0f52de9545c9a2886232c3e41dce36eeb03d805afc68aaac576489303220338bd04c2f9d399fd368580eb69bd4d52fc3df96af24a051e6053cf1aab0509f03d998fe9f1b43babde319ebeb84edb7c02653882b3d30738064bafbc7bd295f50f2acd573653b6c5565b8f63b967ba8668934c2719357ba3759420228be55c5ae4ecaf4480b8bb1a4546a6e2007a5807a7c5c3bcc35f6257c0c15d2c7fe9c88b9c665464e2d6c515bdbe9dc62b0bc3b780df70e1b85197626cb55980bbefe8ccbf5bdd03 Wed Oct 14 11:06:35 2015 : Debug: EAP-Message = 0xff6ab6dd6c81aa7bfc67790725b45516722c18425a87887d1403010001011603010030e8711af27bcdabc15db30c320998bc420c326daf5df8f5acb78bcfc6ad7d068f51f42965f89795ca55b7505dcdcb5e23 Wed Oct 14 11:06:35 2015 : Debug: State = 0x73e0c7cb75e8dea1ed6477b7b8d8584b Wed Oct 14 11:06:35 2015 : Debug: Message-Authenticator = 0xe914b0a35421cf2417c0780f57544a19 Wed Oct 14 11:06:35 2015 : Debug: # Executing section authorize from file /etc/opt/freeradius/sites-enabled/default Wed Oct 14 11:06:35 2015 : Debug: +group authorize { Wed Oct 14 11:06:35 2015 : Debug: ++[preprocess] = ok Wed Oct 14 11:06:35 2015 : Debug: ++[chap] = noop Wed Oct 14 11:06:35 2015 : Debug: ++[mschap] = noop Wed Oct 14 11:06:35 2015 : Debug: ++[digest] = noop Wed Oct 14 11:06:35 2015 : Debug: [suffix] No '@' in User-Name = "hm6", looking up realm NULL Wed Oct 14 11:06:35 2015 : Debug: [suffix] Found realm "NULL" Wed Oct 14 11:06:35 2015 : Debug: [suffix] Adding Stripped-User-Name = "hm6" Wed Oct 14 11:06:35 2015 : Debug: [suffix] Adding Realm = "NULL" Wed Oct 14 11:06:35 2015 : Debug: [suffix] Authentication realm is LOCAL. Wed Oct 14 11:06:35 2015 : Debug: ++[suffix] = ok Wed Oct 14 11:06:35 2015 : Debug: ++? if (Realm =~ /wlan.*gppnetwork\.org/) Wed Oct 14 11:06:35 2015 : Debug: ? Evaluating (Realm =~ /wlan.*gppnetwork\.org/) -> FALSE Wed Oct 14 11:06:35 2015 : Debug: ++? if (Realm =~ /wlan.*gppnetwork\.org/) -> FALSE Wed Oct 14 11:06:35 2015 : Debug: ++? if (Realm == "WiFi.sktelecom.com") Wed Oct 14 11:06:35 2015 : Debug: ? Evaluating (Realm == "WiFi.sktelecom.com") -> FALSE Wed Oct 14 11:06:35 2015 : Debug: ++? if (Realm == "WiFi.sktelecom.com") -> FALSE Wed Oct 14 11:06:35 2015 : Debug: [eap] EAP packet type response id 8 length 253 Wed Oct 14 11:06:35 2015 : Debug: [eap] Continuing tunnel setup. Wed Oct 14 11:06:35 2015 : Debug: ++[eap] = ok Wed Oct 14 11:06:35 2015 : Debug: +} # group authorize = ok Wed Oct 14 11:06:35 2015 : Debug: Found Auth-Type = EAP Wed Oct 14 11:06:35 2015 : Debug: # Executing group from file /etc/opt/freeradius/sites-enabled/default Wed Oct 14 11:06:35 2015 : Debug: +group authenticate { Wed Oct 14 11:06:35 2015 : Debug: [eap] Request found, released from the list Wed Oct 14 11:06:35 2015 : Debug: [eap] EAP/peap Wed Oct 14 11:06:35 2015 : Debug: [eap] processing type peap Wed Oct 14 11:06:35 2015 : Debug: [peap] processing EAP-TLS Wed Oct 14 11:06:35 2015 : Debug: [peap] Length Included Wed Oct 14 11:06:35 2015 : Debug: [peap] eaptls_verify returned 11 Wed Oct 14 11:06:35 2015 : Debug: [peap] TLS_accept: SSLv3 read client key exchange A Wed Oct 14 11:06:35 2015 : Debug: [peap] TLS_accept: SSLv3 read finished A Wed Oct 14 11:06:35 2015 : Debug: [peap] TLS_accept: SSLv3 write change cipher spec A Wed Oct 14 11:06:35 2015 : Debug: [peap] TLS_accept: SSLv3 write finished A Wed Oct 14 11:06:35 2015 : Debug: [peap] TLS_accept: SSLv3 flush data Wed Oct 14 11:06:35 2015 : Debug: [peap] (other): SSL negotiation finished successfully Wed Oct 14 11:06:35 2015 : Debug: [peap] eaptls_process returned 13 Wed Oct 14 11:06:35 2015 : Debug: [peap] EAPTLS_HANDLED Wed Oct 14 11:06:35 2015 : Debug: ++[eap] = handled Wed Oct 14 11:06:35 2015 : Debug: +} # group authenticate = handled Wed Oct 14 11:06:35 2015 : Debug: Sending Access-Challenge packet to host 10.64.76.100 port 32770, id=242, length=0 Wed Oct 14 11:06:35 2015 : Debug: EAP-Message = 0x01090041190014030100010116030100307662a63f3c56e363ae0ba6c6cfc3bb228e30c9e53bdc89b160377579730b189dde7a410bace015576b769ffe1e6cfc5f Wed Oct 14 11:06:35 2015 : Debug: Message-Authenticator = 0x00000000000000000000000000000000 Wed Oct 14 11:06:35 2015 : Debug: State = 0x73e0c7cb74e9dea1ed6477b7b8d8584b Wed Oct 14 11:06:35 2015 : Debug: Finished request 9057460. Wed Oct 14 11:06:35 2015 : Debug: Received Access-Request packet from host 10.64.76.100 port 32770, id=245, length=301 Wed Oct 14 11:06:35 2015 : Debug: User-Name = "hm6" Wed Oct 14 11:06:35 2015 : Debug: Chargeable-User-Identity = "" Wed Oct 14 11:06:35 2015 : Debug: Location-Capable = Civix-Location Wed Oct 14 11:06:35 2015 : Debug: Calling-Station-Id = "14-99-e2-bf-24-70" Wed Oct 14 11:06:35 2015 : Debug: Called-Station-Id = "00-23-eb-2e-3d-f0:Rice Owls" Wed Oct 14 11:06:35 2015 : Debug: NAS-Port = 13 Wed Oct 14 11:06:35 2015 : Debug: Cisco-AVPair = "audit-session-id=0a404c640127a12a561e621e" Wed Oct 14 11:06:35 2015 : Debug: Acct-Session-Id = "561e621e/14:99:e2:bf:24:70/10398428" Wed Oct 14 11:06:35 2015 : Debug: Cisco-AVPair = "mDNS=true" Wed Oct 14 11:06:35 2015 : Debug: NAS-IP-Address = 10.64.76.100 Wed Oct 14 11:06:35 2015 : Debug: NAS-Identifier = "WiSM2-HA1-1" Wed Oct 14 11:06:35 2015 : Debug: Airespace-Wlan-Id = 1 Wed Oct 14 11:06:35 2015 : Debug: Service-Type = Framed-User Wed Oct 14 11:06:35 2015 : Debug: Framed-MTU = 1300 Wed Oct 14 11:06:35 2015 : Debug: NAS-Port-Type = Wireless-802.11 Wed Oct 14 11:06:35 2015 : Debug: Tunnel-Type:0 = VLAN Wed Oct 14 11:06:35 2015 : Debug: Tunnel-Medium-Type:0 = IEEE-802 Wed Oct 14 11:06:35 2015 : Debug: Tunnel-Private-Group-Id:0 = "345" Wed Oct 14 11:06:35 2015 : Debug: EAP-Message = 0x020900061900 Wed Oct 14 11:06:35 2015 : Debug: State = 0x73e0c7cb74e9dea1ed6477b7b8d8584b Wed Oct 14 11:06:35 2015 : Debug: Message-Authenticator = 0xd34aeac8bcbf7eed7fac47d00972a9e6 Wed Oct 14 11:06:35 2015 : Debug: # Executing section authorize from file /etc/opt/freeradius/sites-enabled/default Wed Oct 14 11:06:35 2015 : Debug: +group authorize { Wed Oct 14 11:06:35 2015 : Debug: ++[preprocess] = ok Wed Oct 14 11:06:35 2015 : Debug: ++[chap] = noop Wed Oct 14 11:06:35 2015 : Debug: ++[mschap] = noop Wed Oct 14 11:06:35 2015 : Debug: ++[digest] = noop Wed Oct 14 11:06:35 2015 : Debug: [suffix] No '@' in User-Name = "hm6", looking up realm NULL Wed Oct 14 11:06:35 2015 : Debug: [suffix] Found realm "NULL" Wed Oct 14 11:06:35 2015 : Debug: [suffix] Adding Stripped-User-Name = "hm6" Wed Oct 14 11:06:35 2015 : Debug: [suffix] Adding Realm = "NULL" Wed Oct 14 11:06:35 2015 : Debug: [suffix] Authentication realm is LOCAL. Wed Oct 14 11:06:35 2015 : Debug: ++[suffix] = ok Wed Oct 14 11:06:35 2015 : Debug: ++? if (Realm =~ /wlan.*gppnetwork\.org/) Wed Oct 14 11:06:35 2015 : Debug: ? Evaluating (Realm =~ /wlan.*gppnetwork\.org/) -> FALSE Wed Oct 14 11:06:35 2015 : Debug: ++? if (Realm =~ /wlan.*gppnetwork\.org/) -> FALSE Wed Oct 14 11:06:35 2015 : Debug: ++? if (Realm == "WiFi.sktelecom.com") Wed Oct 14 11:06:35 2015 : Debug: ? Evaluating (Realm == "WiFi.sktelecom.com") -> FALSE Wed Oct 14 11:06:35 2015 : Debug: ++? if (Realm == "WiFi.sktelecom.com") -> FALSE Wed Oct 14 11:06:35 2015 : Debug: [eap] EAP packet type response id 9 length 6 Wed Oct 14 11:06:35 2015 : Debug: [eap] Continuing tunnel setup. Wed Oct 14 11:06:35 2015 : Debug: ++[eap] = ok Wed Oct 14 11:06:35 2015 : Debug: +} # group authorize = ok Wed Oct 14 11:06:35 2015 : Debug: Found Auth-Type = EAP Wed Oct 14 11:06:35 2015 : Debug: # Executing group from file /etc/opt/freeradius/sites-enabled/default Wed Oct 14 11:06:35 2015 : Debug: +group authenticate { Wed Oct 14 11:06:35 2015 : Debug: [eap] Request found, released from the list Wed Oct 14 11:06:35 2015 : Debug: [eap] EAP/peap Wed Oct 14 11:06:35 2015 : Debug: [eap] processing type peap Wed Oct 14 11:06:35 2015 : Debug: [peap] processing EAP-TLS Wed Oct 14 11:06:35 2015 : Debug: [peap] Received TLS ACK Wed Oct 14 11:06:35 2015 : Debug: [peap] ACK handshake is finished Wed Oct 14 11:06:35 2015 : Debug: [peap] eaptls_verify returned 3 Wed Oct 14 11:06:35 2015 : Debug: [peap] eaptls_process returned 3 Wed Oct 14 11:06:35 2015 : Debug: [peap] EAPTLS_SUCCESS Wed Oct 14 11:06:35 2015 : Debug: [peap] Session established. Decoding tunneled attributes. Wed Oct 14 11:06:35 2015 : Debug: [peap] Peap state TUNNEL ESTABLISHED Wed Oct 14 11:06:35 2015 : Debug: ++[eap] = handled Wed Oct 14 11:06:35 2015 : Debug: +} # group authenticate = handled Wed Oct 14 11:06:35 2015 : Debug: Sending Access-Challenge packet to host 10.64.76.100 port 32770, id=245, length=0 Wed Oct 14 11:06:35 2015 : Debug: EAP-Message = 0x010a002b19001703010020ec9929c081653f2d761ea9fc99c531ac00f25f54024307c0b3d44ee320cabaed Wed Oct 14 11:06:35 2015 : Debug: Message-Authenticator = 0x00000000000000000000000000000000 Wed Oct 14 11:06:35 2015 : Debug: State = 0x73e0c7cb7beadea1ed6477b7b8d8584b Wed Oct 14 11:06:35 2015 : Debug: Finished request 9057464. Wed Oct 14 11:06:35 2015 : Debug: Received Access-Request packet from host 10.64.76.100 port 32770, id=246, length=338 Wed Oct 14 11:06:35 2015 : Debug: User-Name = "hm6" Wed Oct 14 11:06:35 2015 : Debug: Chargeable-User-Identity = "" Wed Oct 14 11:06:35 2015 : Debug: Location-Capable = Civix-Location Wed Oct 14 11:06:35 2015 : Debug: Calling-Station-Id = "14-99-e2-bf-24-70" Wed Oct 14 11:06:35 2015 : Debug: Called-Station-Id = "00-23-eb-2e-3d-f0:Rice Owls" Wed Oct 14 11:06:35 2015 : Debug: NAS-Port = 13 Wed Oct 14 11:06:35 2015 : Debug: Cisco-AVPair = "audit-session-id=0a404c640127a12a561e621e" Wed Oct 14 11:06:35 2015 : Debug: Acct-Session-Id = "561e621e/14:99:e2:bf:24:70/10398428" Wed Oct 14 11:06:35 2015 : Debug: Cisco-AVPair = "mDNS=true" Wed Oct 14 11:06:35 2015 : Debug: NAS-IP-Address = 10.64.76.100 Wed Oct 14 11:06:35 2015 : Debug: NAS-Identifier = "WiSM2-HA1-1" Wed Oct 14 11:06:35 2015 : Debug: Airespace-Wlan-Id = 1 Wed Oct 14 11:06:35 2015 : Debug: Service-Type = Framed-User Wed Oct 14 11:06:35 2015 : Debug: Framed-MTU = 1300 Wed Oct 14 11:06:35 2015 : Debug: NAS-Port-Type = Wireless-802.11 Wed Oct 14 11:06:35 2015 : Debug: Tunnel-Type:0 = VLAN Wed Oct 14 11:06:35 2015 : Debug: Tunnel-Medium-Type:0 = IEEE-802 Wed Oct 14 11:06:35 2015 : Debug: Tunnel-Private-Group-Id:0 = "345" Wed Oct 14 11:06:35 2015 : Debug: EAP-Message = 0x020a002b19001703010020ce55956ebf5b9b20c665c479712bd7520e8ea1beaf28d20983bab2da85fcc0a7 Wed Oct 14 11:06:35 2015 : Debug: State = 0x73e0c7cb7beadea1ed6477b7b8d8584b Wed Oct 14 11:06:35 2015 : Debug: Message-Authenticator = 0x54e5615d85a4b330ce7437c0a33767b9 Wed Oct 14 11:06:35 2015 : Debug: # Executing section authorize from file /etc/opt/freeradius/sites-enabled/default Wed Oct 14 11:06:35 2015 : Debug: +group authorize { Wed Oct 14 11:06:35 2015 : Debug: ++[preprocess] = ok Wed Oct 14 11:06:35 2015 : Debug: ++[chap] = noop Wed Oct 14 11:06:35 2015 : Debug: ++[mschap] = noop Wed Oct 14 11:06:35 2015 : Debug: ++[digest] = noop Wed Oct 14 11:06:35 2015 : Debug: [suffix] No '@' in User-Name = "hm6", looking up realm NULL Wed Oct 14 11:06:35 2015 : Debug: [suffix] Found realm "NULL" Wed Oct 14 11:06:35 2015 : Debug: [suffix] Adding Stripped-User-Name = "hm6" Wed Oct 14 11:06:35 2015 : Debug: [suffix] Adding Realm = "NULL" Wed Oct 14 11:06:35 2015 : Debug: [suffix] Authentication realm is LOCAL. Wed Oct 14 11:06:35 2015 : Debug: ++[suffix] = ok Wed Oct 14 11:06:35 2015 : Debug: ++? if (Realm =~ /wlan.*gppnetwork\.org/) Wed Oct 14 11:06:35 2015 : Debug: ? Evaluating (Realm =~ /wlan.*gppnetwork\.org/) -> FALSE Wed Oct 14 11:06:35 2015 : Debug: ++? if (Realm =~ /wlan.*gppnetwork\.org/) -> FALSE Wed Oct 14 11:06:35 2015 : Debug: ++? if (Realm == "WiFi.sktelecom.com") Wed Oct 14 11:06:35 2015 : Debug: ? Evaluating (Realm == "WiFi.sktelecom.com") -> FALSE Wed Oct 14 11:06:35 2015 : Debug: ++? if (Realm == "WiFi.sktelecom.com") -> FALSE Wed Oct 14 11:06:35 2015 : Debug: [eap] EAP packet type response id 10 length 43 Wed Oct 14 11:06:35 2015 : Debug: [eap] Continuing tunnel setup. Wed Oct 14 11:06:35 2015 : Debug: ++[eap] = ok Wed Oct 14 11:06:35 2015 : Debug: +} # group authorize = ok Wed Oct 14 11:06:35 2015 : Debug: Found Auth-Type = EAP Wed Oct 14 11:06:35 2015 : Debug: # Executing group from file /etc/opt/freeradius/sites-enabled/default Wed Oct 14 11:06:35 2015 : Debug: +group authenticate { Wed Oct 14 11:06:35 2015 : Debug: [eap] Request found, released from the list Wed Oct 14 11:06:35 2015 : Debug: [eap] EAP/peap Wed Oct 14 11:06:35 2015 : Debug: [eap] processing type peap Wed Oct 14 11:06:35 2015 : Debug: [peap] processing EAP-TLS Wed Oct 14 11:06:35 2015 : Debug: [peap] eaptls_verify returned 7 Wed Oct 14 11:06:35 2015 : Debug: [peap] Done initial handshake Wed Oct 14 11:06:35 2015 : Debug: [peap] eaptls_process returned 7 Wed Oct 14 11:06:35 2015 : Debug: [peap] EAPTLS_OK Wed Oct 14 11:06:35 2015 : Debug: [peap] Session established. Decoding tunneled attributes. Wed Oct 14 11:06:35 2015 : Debug: [peap] Peap state WAITING FOR INNER IDENTITY Wed Oct 14 11:06:35 2015 : Debug: [peap] Identity - hm6 Wed Oct 14 11:06:35 2015 : Debug: [peap] Got inner identity 'hm6' Wed Oct 14 11:06:35 2015 : Debug: [peap] Setting default EAP type for tunneled EAP session. Wed Oct 14 11:06:35 2015 : Debug: [peap] Setting User-Name to hm6 Wed Oct 14 11:06:35 2015 : Debug: # Executing section authorize from file /etc/opt/freeradius/sites-enabled/inner-tunnel Wed Oct 14 11:06:35 2015 : Debug: +group authorize { Wed Oct 14 11:06:35 2015 : Debug: ++[preprocess] = ok Wed Oct 14 11:06:35 2015 : Debug: ++[chap] = noop Wed Oct 14 11:06:35 2015 : Debug: ++[mschap] = noop Wed Oct 14 11:06:35 2015 : Debug: ++[unix] = notfound Wed Oct 14 11:06:35 2015 : Debug: [suffix] No '@' in User-Name = "hm6", looking up realm NULL Wed Oct 14 11:06:35 2015 : Debug: [suffix] Found realm "NULL" Wed Oct 14 11:06:35 2015 : Debug: [suffix] Adding Stripped-User-Name = "hm6" Wed Oct 14 11:06:35 2015 : Debug: [suffix] Adding Realm = "NULL" Wed Oct 14 11:06:35 2015 : Debug: [suffix] Authentication realm is LOCAL. Wed Oct 14 11:06:35 2015 : Debug: ++[suffix] = ok Wed Oct 14 11:06:35 2015 : Debug: ++update control { Wed Oct 14 11:06:35 2015 : Debug: ++} # update control = noop Wed Oct 14 11:06:35 2015 : Debug: [eap] EAP packet type response id 10 length 8 Wed Oct 14 11:06:35 2015 : Debug: [eap] No EAP Start, assuming it's an on-going EAP conversation Wed Oct 14 11:06:35 2015 : Debug: ++[eap] = updated Wed Oct 14 11:06:35 2015 : Debug: [files] users: Matched entry DEFAULT at line 92 Wed Oct 14 11:06:35 2015 : Debug: ++[files] = ok Wed Oct 14 11:06:35 2015 : Debug: ++? if (control:Auth-Type == Kerberos) Wed Oct 14 11:06:35 2015 : Debug: ? Evaluating (control:Auth-Type == Kerberos) -> FALSE Wed Oct 14 11:06:35 2015 : Debug: ++? if (control:Auth-Type == Kerberos) -> FALSE Wed Oct 14 11:06:35 2015 : Debug: ++load-balance redundant_ldap { Wed Oct 14 11:06:35 2015 : Debug: ++redundant-load-balance group redundant_ldap { Wed Oct 14 11:06:35 2015 : Debug: [ldap2] performing user authorization for hm6 Wed Oct 14 11:06:35 2015 : Debug: [ldap2] expand: %{Stripped-User-Name} -> hm6 Wed Oct 14 11:06:35 2015 : Debug: [ldap2] expand: (uid=%{%{Stripped-User-Name}:-%{User-Name}}) -> (uid=hm6) Wed Oct 14 11:06:35 2015 : Debug: [ldap2] expand: dc=rice,dc=edu -> dc=rice,dc=edu Wed Oct 14 11:06:35 2015 : Debug: [ldap2] checking if remote access for hm6 is allowed by riceClass Wed Oct 14 11:06:35 2015 : Debug: [ldap2] looking for check items in directory... Wed Oct 14 11:06:35 2015 : Debug: [ldap2] looking for reply items in directory... Wed Oct 14 11:06:35 2015 : Debug: [ldap2] user hm6 authorized to use remote access Wed Oct 14 11:06:35 2015 : Debug: +++[ldap2] = ok Wed Oct 14 11:06:35 2015 : Debug: ++} # redundant-load-balance group redundant_ldap = ok Wed Oct 14 11:06:35 2015 : Debug: ++? if (reply:Connect-Info =~ /[a-z]* student/) Wed Oct 14 11:06:35 2015 : Debug: ? Evaluating (reply:Connect-Info =~ /[a-z]* student/) -> TRUE Wed Oct 14 11:06:35 2015 : Debug: ++? if (reply:Connect-Info =~ /[a-z]* student/) -> TRUE Wed Oct 14 11:06:35 2015 : Debug: ++if (reply:Connect-Info =~ /[a-z]* student/) { Wed Oct 14 11:06:35 2015 : Debug: +++update reply { Wed Oct 14 11:06:35 2015 : Debug: +++} # update reply = noop Wed Oct 14 11:06:35 2015 : Debug: ++} # if (reply:Connect-Info =~ /[a-z]* student/) = noop Wed Oct 14 11:06:35 2015 : Debug: ++ ... skipping elsif for request 9057465: Preceding "if" was taken Wed Oct 14 11:06:35 2015 : Debug: ++ ... skipping elsif for request 9057465: Preceding "if" was taken Wed Oct 14 11:06:35 2015 : Debug: ++ ... skipping elsif for request 9057465: Preceding "if" was taken Wed Oct 14 11:06:35 2015 : Debug: ++? if ((Hint == "JOINstudent" ) && (reply:Connect-Info == "staff")) Wed Oct 14 11:06:35 2015 : Debug: (Attribute Hint was not found) Wed Oct 14 11:06:35 2015 : Debug: ?? Evaluating (Hint == "JOINstudent" ) -> FALSE Wed Oct 14 11:06:35 2015 : Debug: ?? Skipping (reply:Connect-Info == "staff") Wed Oct 14 11:06:35 2015 : Debug: ++? if ((Hint == "JOINstudent" ) && (reply:Connect-Info == "staff")) -> FALSE Wed Oct 14 11:06:35 2015 : Debug: ++[perl] = updated Wed Oct 14 11:06:35 2015 : Debug: ++update reply { Wed Oct 14 11:06:35 2015 : Debug: expand: %{reply:Tunnel-Private-Group-Id} -> student Wed Oct 14 11:06:35 2015 : Debug: ++} # update reply = noop Wed Oct 14 11:06:35 2015 : Debug: ++[expiration] = noop Wed Oct 14 11:06:35 2015 : Debug: ++[logintime] = noop Wed Oct 14 11:06:35 2015 : Debug: ++[pap] = noop Wed Oct 14 11:06:35 2015 : Debug: +} # group authorize = updated Wed Oct 14 11:06:35 2015 : Debug: Found Auth-Type = EAP Wed Oct 14 11:06:35 2015 : Debug: # Executing group from file /etc/opt/freeradius/sites-enabled/inner-tunnel Wed Oct 14 11:06:35 2015 : Debug: +group authenticate { Wed Oct 14 11:06:35 2015 : Debug: [eap] EAP Identity Wed Oct 14 11:06:35 2015 : Debug: [eap] processing type mschapv2 Wed Oct 14 11:06:35 2015 : Debug: ++[eap] = handled Wed Oct 14 11:06:35 2015 : Debug: +} # group authenticate = handled Wed Oct 14 11:06:35 2015 : Debug: [peap] Got tunneled Access-Challenge Wed Oct 14 11:06:35 2015 : Debug: ++[eap] = handled Wed Oct 14 11:06:35 2015 : Debug: +} # group authenticate = handled Wed Oct 14 11:06:35 2015 : Debug: Sending Access-Challenge packet to host 10.64.76.100 port 32770, id=246, length=0 Wed Oct 14 11:06:35 2015 : Debug: EAP-Message = 0x010b003b1900170301003049d8728f2df8f7cc708214c08c1945ca8c14a7c6b8fdef8d35742122d5e14ca7e0464ddd319c24f09bf1e81b33d4fd0b Wed Oct 14 11:06:35 2015 : Debug: Message-Authenticator = 0x00000000000000000000000000000000 Wed Oct 14 11:06:35 2015 : Debug: State = 0x73e0c7cb7aebdea1ed6477b7b8d8584b Wed Oct 14 11:06:35 2015 : Debug: Finished request 9057465. Wed Oct 14 11:06:35 2015 : Debug: Received Access-Request packet from host 10.64.76.100 port 32770, id=248, length=386 Wed Oct 14 11:06:35 2015 : Debug: User-Name = "hm6" Wed Oct 14 11:06:35 2015 : Debug: Chargeable-User-Identity = "" Wed Oct 14 11:06:35 2015 : Debug: Location-Capable = Civix-Location Wed Oct 14 11:06:35 2015 : Debug: Calling-Station-Id = "14-99-e2-bf-24-70" Wed Oct 14 11:06:35 2015 : Debug: Called-Station-Id = "00-23-eb-2e-3d-f0:Rice Owls" Wed Oct 14 11:06:35 2015 : Debug: NAS-Port = 13 Wed Oct 14 11:06:35 2015 : Debug: Cisco-AVPair = "audit-session-id=0a404c640127a12a561e621e" Wed Oct 14 11:06:35 2015 : Debug: Acct-Session-Id = "561e621e/14:99:e2:bf:24:70/10398428" Wed Oct 14 11:06:35 2015 : Debug: Cisco-AVPair = "mDNS=true" Wed Oct 14 11:06:35 2015 : Debug: NAS-IP-Address = 10.64.76.100 Wed Oct 14 11:06:35 2015 : Debug: NAS-Identifier = "WiSM2-HA1-1" Wed Oct 14 11:06:35 2015 : Debug: Airespace-Wlan-Id = 1 Wed Oct 14 11:06:35 2015 : Debug: Service-Type = Framed-User Wed Oct 14 11:06:35 2015 : Debug: Framed-MTU = 1300 Wed Oct 14 11:06:35 2015 : Debug: NAS-Port-Type = Wireless-802.11 Wed Oct 14 11:06:35 2015 : Debug: Tunnel-Type:0 = VLAN Wed Oct 14 11:06:35 2015 : Debug: Tunnel-Medium-Type:0 = IEEE-802 Wed Oct 14 11:06:35 2015 : Debug: Tunnel-Private-Group-Id:0 = "345" Wed Oct 14 11:06:35 2015 : Debug: EAP-Message = 0x020b005b19001703010050e914c55f667f3fc177ef910567dd74dd7c6b3be9c954a26b8c82a1d982237052a2ab687f9baaf73cd44d1adde1bf238e0f41bc8c8d7d6b49c95a5eb168c61d45ee229da0613c2d77e08cff12f05fe0a1 Wed Oct 14 11:06:35 2015 : Debug: State = 0x73e0c7cb7aebdea1ed6477b7b8d8584b Wed Oct 14 11:06:35 2015 : Debug: Message-Authenticator = 0x4bec218eb833a573f94413c2d44f68cc Wed Oct 14 11:06:35 2015 : Debug: # Executing section authorize from file /etc/opt/freeradius/sites-enabled/default Wed Oct 14 11:06:35 2015 : Debug: +group authorize { Wed Oct 14 11:06:35 2015 : Debug: ++[preprocess] = ok Wed Oct 14 11:06:35 2015 : Debug: ++[chap] = noop Wed Oct 14 11:06:35 2015 : Debug: ++[mschap] = noop Wed Oct 14 11:06:35 2015 : Debug: ++[digest] = noop Wed Oct 14 11:06:35 2015 : Debug: [suffix] No '@' in User-Name = "hm6", looking up realm NULL Wed Oct 14 11:06:35 2015 : Debug: [suffix] Found realm "NULL" Wed Oct 14 11:06:35 2015 : Debug: [suffix] Adding Stripped-User-Name = "hm6" Wed Oct 14 11:06:35 2015 : Debug: [suffix] Adding Realm = "NULL" Wed Oct 14 11:06:35 2015 : Debug: [suffix] Authentication realm is LOCAL. Wed Oct 14 11:06:35 2015 : Debug: ++[suffix] = ok Wed Oct 14 11:06:35 2015 : Debug: ++? if (Realm =~ /wlan.*gppnetwork\.org/) Wed Oct 14 11:06:35 2015 : Debug: ? Evaluating (Realm =~ /wlan.*gppnetwork\.org/) -> FALSE Wed Oct 14 11:06:35 2015 : Debug: ++? if (Realm =~ /wlan.*gppnetwork\.org/) -> FALSE Wed Oct 14 11:06:35 2015 : Debug: ++? if (Realm == "WiFi.sktelecom.com") Wed Oct 14 11:06:35 2015 : Debug: ? Evaluating (Realm == "WiFi.sktelecom.com") -> FALSE Wed Oct 14 11:06:35 2015 : Debug: ++? if (Realm == "WiFi.sktelecom.com") -> FALSE Wed Oct 14 11:06:35 2015 : Debug: [eap] EAP packet type response id 11 length 91 Wed Oct 14 11:06:35 2015 : Debug: [eap] Continuing tunnel setup. Wed Oct 14 11:06:35 2015 : Debug: ++[eap] = ok Wed Oct 14 11:06:35 2015 : Debug: +} # group authorize = ok Wed Oct 14 11:06:35 2015 : Debug: Found Auth-Type = EAP Wed Oct 14 11:06:35 2015 : Debug: # Executing group from file /etc/opt/freeradius/sites-enabled/default Wed Oct 14 11:06:35 2015 : Debug: +group authenticate { Wed Oct 14 11:06:35 2015 : Debug: [eap] Request found, released from the list Wed Oct 14 11:06:35 2015 : Debug: [eap] EAP/peap Wed Oct 14 11:06:35 2015 : Debug: [eap] processing type peap Wed Oct 14 11:06:35 2015 : Debug: [peap] processing EAP-TLS Wed Oct 14 11:06:35 2015 : Debug: [peap] eaptls_verify returned 7 Wed Oct 14 11:06:35 2015 : Debug: [peap] Done initial handshake Wed Oct 14 11:06:35 2015 : Debug: [peap] eaptls_process returned 7 Wed Oct 14 11:06:35 2015 : Debug: [peap] EAPTLS_OK Wed Oct 14 11:06:35 2015 : Debug: [peap] Session established. Decoding tunneled attributes. Wed Oct 14 11:06:35 2015 : Debug: [peap] Peap state phase2 Wed Oct 14 11:06:35 2015 : Debug: [peap] EAP type mschapv2 Wed Oct 14 11:06:35 2015 : Debug: [peap] Setting User-Name to hm6 Wed Oct 14 11:06:35 2015 : Debug: # Executing section authorize from file /etc/opt/freeradius/sites-enabled/inner-tunnel Wed Oct 14 11:06:35 2015 : Debug: +group authorize { Wed Oct 14 11:06:35 2015 : Debug: ++[preprocess] = ok Wed Oct 14 11:06:35 2015 : Debug: ++[chap] = noop Wed Oct 14 11:06:35 2015 : Debug: ++[mschap] = noop Wed Oct 14 11:06:35 2015 : Debug: ++[unix] = notfound Wed Oct 14 11:06:35 2015 : Debug: [suffix] No '@' in User-Name = "hm6", looking up realm NULL Wed Oct 14 11:06:35 2015 : Debug: [suffix] Found realm "NULL" Wed Oct 14 11:06:35 2015 : Debug: [suffix] Adding Stripped-User-Name = "hm6" Wed Oct 14 11:06:35 2015 : Debug: [suffix] Adding Realm = "NULL" Wed Oct 14 11:06:35 2015 : Debug: [suffix] Authentication realm is LOCAL. Wed Oct 14 11:06:35 2015 : Debug: ++[suffix] = ok Wed Oct 14 11:06:35 2015 : Debug: ++update control { Wed Oct 14 11:06:35 2015 : Debug: ++} # update control = noop Wed Oct 14 11:06:35 2015 : Debug: [eap] EAP packet type response id 11 length 62 Wed Oct 14 11:06:35 2015 : Debug: [eap] No EAP Start, assuming it's an on-going EAP conversation Wed Oct 14 11:06:35 2015 : Debug: ++[eap] = updated Wed Oct 14 11:06:35 2015 : Debug: [files] users: Matched entry DEFAULT at line 92 Wed Oct 14 11:06:35 2015 : Debug: ++[files] = ok Wed Oct 14 11:06:35 2015 : Debug: ++? if (control:Auth-Type == Kerberos) Wed Oct 14 11:06:35 2015 : Debug: ? Evaluating (control:Auth-Type == Kerberos) -> FALSE Wed Oct 14 11:06:35 2015 : Debug: ++? if (control:Auth-Type == Kerberos) -> FALSE Wed Oct 14 11:06:35 2015 : Debug: ++load-balance redundant_ldap { Wed Oct 14 11:06:35 2015 : Debug: ++redundant-load-balance group redundant_ldap { Wed Oct 14 11:06:35 2015 : Debug: [ldap2] performing user authorization for hm6 Wed Oct 14 11:06:35 2015 : Debug: [ldap2] expand: %{Stripped-User-Name} -> hm6 Wed Oct 14 11:06:35 2015 : Debug: [ldap2] expand: (uid=%{%{Stripped-User-Name}:-%{User-Name}}) -> (uid=hm6) Wed Oct 14 11:06:35 2015 : Debug: [ldap2] expand: dc=rice,dc=edu -> dc=rice,dc=edu Wed Oct 14 11:06:35 2015 : Debug: [ldap2] checking if remote access for hm6 is allowed by riceClass Wed Oct 14 11:06:35 2015 : Debug: [ldap2] looking for check items in directory... Wed Oct 14 11:06:35 2015 : Debug: [ldap2] looking for reply items in directory... Wed Oct 14 11:06:35 2015 : Debug: [ldap2] user hm6 authorized to use remote access Wed Oct 14 11:06:35 2015 : Debug: +++[ldap2] = ok Wed Oct 14 11:06:35 2015 : Debug: ++} # redundant-load-balance group redundant_ldap = ok Wed Oct 14 11:06:35 2015 : Debug: ++? if (reply:Connect-Info =~ /[a-z]* student/) Wed Oct 14 11:06:35 2015 : Debug: ? Evaluating (reply:Connect-Info =~ /[a-z]* student/) -> TRUE Wed Oct 14 11:06:35 2015 : Debug: ++? if (reply:Connect-Info =~ /[a-z]* student/) -> TRUE Wed Oct 14 11:06:35 2015 : Debug: ++if (reply:Connect-Info =~ /[a-z]* student/) { Wed Oct 14 11:06:35 2015 : Debug: +++update reply { Wed Oct 14 11:06:35 2015 : Debug: +++} # update reply = noop Wed Oct 14 11:06:35 2015 : Debug: ++} # if (reply:Connect-Info =~ /[a-z]* student/) = noop Wed Oct 14 11:06:35 2015 : Debug: ++ ... skipping elsif for request 9057467: Preceding "if" was taken Wed Oct 14 11:06:35 2015 : Debug: ++ ... skipping elsif for request 9057467: Preceding "if" was taken Wed Oct 14 11:06:35 2015 : Debug: ++ ... skipping elsif for request 9057467: Preceding "if" was taken Wed Oct 14 11:06:35 2015 : Debug: ++? if ((Hint == "JOINstudent" ) && (reply:Connect-Info == "staff")) Wed Oct 14 11:06:35 2015 : Debug: (Attribute Hint was not found) Wed Oct 14 11:06:35 2015 : Debug: ?? Evaluating (Hint == "JOINstudent" ) -> FALSE Wed Oct 14 11:06:35 2015 : Debug: ?? Skipping (reply:Connect-Info == "staff") Wed Oct 14 11:06:35 2015 : Debug: ++? if ((Hint == "JOINstudent" ) && (reply:Connect-Info == "staff")) -> FALSE Wed Oct 14 11:06:35 2015 : Debug: ++[perl] = updated Wed Oct 14 11:06:35 2015 : Debug: ++update reply { Wed Oct 14 11:06:35 2015 : Debug: expand: %{reply:Tunnel-Private-Group-Id} -> student Wed Oct 14 11:06:35 2015 : Debug: ++} # update reply = noop Wed Oct 14 11:06:35 2015 : Debug: ++[expiration] = noop Wed Oct 14 11:06:35 2015 : Debug: ++[logintime] = noop Wed Oct 14 11:06:35 2015 : Debug: ++[pap] = noop Wed Oct 14 11:06:35 2015 : Debug: +} # group authorize = updated Wed Oct 14 11:06:35 2015 : Debug: Found Auth-Type = EAP Wed Oct 14 11:06:35 2015 : Debug: # Executing group from file /etc/opt/freeradius/sites-enabled/inner-tunnel Wed Oct 14 11:06:35 2015 : Debug: +group authenticate { Wed Oct 14 11:06:35 2015 : Debug: [eap] Request found, released from the list Wed Oct 14 11:06:35 2015 : Debug: [eap] EAP/mschapv2 Wed Oct 14 11:06:35 2015 : Debug: [eap] processing type mschapv2 Wed Oct 14 11:06:35 2015 : Debug: [mschapv2] # Executing group from file /etc/opt/freeradius/sites-enabled/inner-tunnel Wed Oct 14 11:06:35 2015 : Debug: [mschapv2] +group MS-CHAP { Wed Oct 14 11:06:35 2015 : Debug: [mschap] Creating challenge hash with username: hm6 Wed Oct 14 11:06:35 2015 : Debug: [mschap] Client is using MS-CHAPv2 for hm6, we need NT-Password Wed Oct 14 11:06:35 2015 : Debug: [mschap] expand: %{Stripped-User-Name} -> hm6 Wed Oct 14 11:06:35 2015 : Debug: [mschap] expand: --username=%{%{Stripped-User-Name}:-%{%{mschap:User-Name}:-%{User-Name}}} -> --username=hm6 Wed Oct 14 11:06:35 2015 : Debug: [mschap] No NT-Domain was found in the User-Name. Wed Oct 14 11:06:35 2015 : Debug: [mschap] expand: --domain=%{mschap:NT-Domain:-ADRICE} -> --domain= Wed Oct 14 11:06:35 2015 : Debug: [mschap] Creating challenge hash with username: hm6 Wed Oct 14 11:06:35 2015 : Debug: [mschap] expand: --challenge=%{mschap:Challenge:-00} -> --challenge=c6b6be6394fb80be Wed Oct 14 11:06:35 2015 : Debug: [mschap] expand: --nt-response=%{mschap:NT-Response:-00} -> --nt-response=c93bab6136a2420593d3dd328dbda3d5bf887ce07b3887bb Wed Oct 14 11:06:35 2015 : Debug: [mschap] Exec: program returned: 0 Wed Oct 14 11:06:35 2015 : Debug: [mschap] adding MS-CHAPv2 MPPE keys Wed Oct 14 11:06:35 2015 : Debug: ++[mschap] = ok Wed Oct 14 11:06:35 2015 : Debug: +} # group MS-CHAP = ok Wed Oct 14 11:06:35 2015 : Debug: ++[eap] = handled Wed Oct 14 11:06:35 2015 : Debug: +} # group authenticate = handled Wed Oct 14 11:06:35 2015 : Debug: [peap] Got tunneled Access-Challenge Wed Oct 14 11:06:35 2015 : Debug: ++[eap] = handled Wed Oct 14 11:06:35 2015 : Debug: +} # group authenticate = handled Wed Oct 14 11:06:35 2015 : Debug: Sending Access-Challenge packet to host 10.64.76.100 port 32770, id=248, length=0 Wed Oct 14 11:06:35 2015 : Debug: EAP-Message = 0x010c005b190017030100500e527fefe8b2ef735b397f33660e0a46f0587eb4809f047fe575068e013b42bbcf7f18c2a2fe1c440d3380e4babf39811441fd5814761722b160bc0cd5851dcd1d8df9d87063c9d0ba38fc1f2ed2592d Wed Oct 14 11:06:35 2015 : Debug: Message-Authenticator = 0x00000000000000000000000000000000 Wed Oct 14 11:06:35 2015 : Debug: State = 0x73e0c7cb79ecdea1ed6477b7b8d8584b Wed Oct 14 11:06:35 2015 : Debug: Finished request 9057467. Wed Oct 14 11:06:35 2015 : Debug: Received Access-Request packet from host 10.64.76.100 port 32770, id=255, length=338 Wed Oct 14 11:06:35 2015 : Debug: User-Name = "hm6" Wed Oct 14 11:06:35 2015 : Debug: Chargeable-User-Identity = "" Wed Oct 14 11:06:35 2015 : Debug: Location-Capable = Civix-Location Wed Oct 14 11:06:35 2015 : Debug: Calling-Station-Id = "14-99-e2-bf-24-70" Wed Oct 14 11:06:35 2015 : Debug: Called-Station-Id = "00-23-eb-2e-3d-f0:Rice Owls" Wed Oct 14 11:06:35 2015 : Debug: NAS-Port = 13 Wed Oct 14 11:06:35 2015 : Debug: Cisco-AVPair = "audit-session-id=0a404c640127a12a561e621e" Wed Oct 14 11:06:35 2015 : Debug: Acct-Session-Id = "561e621e/14:99:e2:bf:24:70/10398428" Wed Oct 14 11:06:35 2015 : Debug: Cisco-AVPair = "mDNS=true" Wed Oct 14 11:06:35 2015 : Debug: NAS-IP-Address = 10.64.76.100 Wed Oct 14 11:06:35 2015 : Debug: NAS-Identifier = "WiSM2-HA1-1" Wed Oct 14 11:06:35 2015 : Debug: Airespace-Wlan-Id = 1 Wed Oct 14 11:06:35 2015 : Debug: Service-Type = Framed-User Wed Oct 14 11:06:35 2015 : Debug: Framed-MTU = 1300 Wed Oct 14 11:06:35 2015 : Debug: NAS-Port-Type = Wireless-802.11 Wed Oct 14 11:06:35 2015 : Debug: Tunnel-Type:0 = VLAN Wed Oct 14 11:06:35 2015 : Debug: Tunnel-Medium-Type:0 = IEEE-802 Wed Oct 14 11:06:35 2015 : Debug: Tunnel-Private-Group-Id:0 = "345" Wed Oct 14 11:06:35 2015 : Debug: EAP-Message = 0x020c002b19001703010020ef40d3f6b32d3c0667bfbe62768fb20209c755b908c286191a3d9ec491646db5 Wed Oct 14 11:06:35 2015 : Debug: State = 0x73e0c7cb79ecdea1ed6477b7b8d8584b Wed Oct 14 11:06:35 2015 : Debug: Message-Authenticator = 0x6ed39cb5049e3132b5ebdf02704a4102 Wed Oct 14 11:06:35 2015 : Debug: # Executing section authorize from file /etc/opt/freeradius/sites-enabled/default Wed Oct 14 11:06:35 2015 : Debug: +group authorize { Wed Oct 14 11:06:35 2015 : Debug: ++[preprocess] = ok Wed Oct 14 11:06:35 2015 : Debug: ++[chap] = noop Wed Oct 14 11:06:35 2015 : Debug: ++[mschap] = noop Wed Oct 14 11:06:35 2015 : Debug: ++[digest] = noop Wed Oct 14 11:06:35 2015 : Debug: [suffix] No '@' in User-Name = "hm6", looking up realm NULL Wed Oct 14 11:06:35 2015 : Debug: [suffix] Found realm "NULL" Wed Oct 14 11:06:35 2015 : Debug: [suffix] Adding Stripped-User-Name = "hm6" Wed Oct 14 11:06:35 2015 : Debug: [suffix] Adding Realm = "NULL" Wed Oct 14 11:06:35 2015 : Debug: [suffix] Authentication realm is LOCAL. Wed Oct 14 11:06:35 2015 : Debug: ++[suffix] = ok Wed Oct 14 11:06:35 2015 : Debug: ++? if (Realm =~ /wlan.*gppnetwork\.org/) Wed Oct 14 11:06:35 2015 : Debug: ? Evaluating (Realm =~ /wlan.*gppnetwork\.org/) -> FALSE Wed Oct 14 11:06:35 2015 : Debug: ++? if (Realm =~ /wlan.*gppnetwork\.org/) -> FALSE Wed Oct 14 11:06:35 2015 : Debug: ++? if (Realm == "WiFi.sktelecom.com") Wed Oct 14 11:06:35 2015 : Debug: ? Evaluating (Realm == "WiFi.sktelecom.com") -> FALSE Wed Oct 14 11:06:35 2015 : Debug: ++? if (Realm == "WiFi.sktelecom.com") -> FALSE Wed Oct 14 11:06:35 2015 : Debug: [eap] EAP packet type response id 12 length 43 Wed Oct 14 11:06:35 2015 : Debug: [eap] Continuing tunnel setup. Wed Oct 14 11:06:35 2015 : Debug: ++[eap] = ok Wed Oct 14 11:06:35 2015 : Debug: +} # group authorize = ok Wed Oct 14 11:06:35 2015 : Debug: Found Auth-Type = EAP Wed Oct 14 11:06:35 2015 : Debug: # Executing group from file /etc/opt/freeradius/sites-enabled/default Wed Oct 14 11:06:35 2015 : Debug: +group authenticate { Wed Oct 14 11:06:35 2015 : Debug: [eap] Request found, released from the list Wed Oct 14 11:06:35 2015 : Debug: [eap] EAP/peap Wed Oct 14 11:06:35 2015 : Debug: [eap] processing type peap Wed Oct 14 11:06:35 2015 : Debug: [peap] processing EAP-TLS Wed Oct 14 11:06:35 2015 : Debug: [peap] eaptls_verify returned 7 Wed Oct 14 11:06:35 2015 : Debug: [peap] Done initial handshake Wed Oct 14 11:06:35 2015 : Debug: [peap] eaptls_process returned 7 Wed Oct 14 11:06:35 2015 : Debug: [peap] EAPTLS_OK Wed Oct 14 11:06:35 2015 : Debug: [peap] Session established. Decoding tunneled attributes. Wed Oct 14 11:06:35 2015 : Debug: [peap] Peap state phase2 Wed Oct 14 11:06:35 2015 : Debug: [peap] EAP type mschapv2 Wed Oct 14 11:06:35 2015 : Debug: [peap] Setting User-Name to hm6 Wed Oct 14 11:06:35 2015 : Debug: # Executing section authorize from file /etc/opt/freeradius/sites-enabled/inner-tunnel Wed Oct 14 11:06:35 2015 : Debug: +group authorize { Wed Oct 14 11:06:35 2015 : Debug: ++[preprocess] = ok Wed Oct 14 11:06:35 2015 : Debug: ++[chap] = noop Wed Oct 14 11:06:35 2015 : Debug: ++[mschap] = noop Wed Oct 14 11:06:35 2015 : Debug: ++[unix] = notfound Wed Oct 14 11:06:35 2015 : Debug: [suffix] No '@' in User-Name = "hm6", looking up realm NULL Wed Oct 14 11:06:35 2015 : Debug: [suffix] Found realm "NULL" Wed Oct 14 11:06:35 2015 : Debug: [suffix] Adding Stripped-User-Name = "hm6" Wed Oct 14 11:06:35 2015 : Debug: [suffix] Adding Realm = "NULL" Wed Oct 14 11:06:35 2015 : Debug: [suffix] Authentication realm is LOCAL. Wed Oct 14 11:06:35 2015 : Debug: ++[suffix] = ok Wed Oct 14 11:06:35 2015 : Debug: ++update control { Wed Oct 14 11:06:35 2015 : Debug: ++} # update control = noop Wed Oct 14 11:06:35 2015 : Debug: [eap] EAP packet type response id 12 length 6 Wed Oct 14 11:06:35 2015 : Debug: [eap] No EAP Start, assuming it's an on-going EAP conversation Wed Oct 14 11:06:35 2015 : Debug: ++[eap] = updated Wed Oct 14 11:06:35 2015 : Debug: [files] users: Matched entry DEFAULT at line 92 Wed Oct 14 11:06:35 2015 : Debug: ++[files] = ok Wed Oct 14 11:06:35 2015 : Debug: ++? if (control:Auth-Type == Kerberos) Wed Oct 14 11:06:35 2015 : Debug: ? Evaluating (control:Auth-Type == Kerberos) -> FALSE Wed Oct 14 11:06:35 2015 : Debug: ++? if (control:Auth-Type == Kerberos) -> FALSE Wed Oct 14 11:06:35 2015 : Debug: ++load-balance redundant_ldap { Wed Oct 14 11:06:35 2015 : Debug: ++redundant-load-balance group redundant_ldap { Wed Oct 14 11:06:35 2015 : Debug: [ldap1] performing user authorization for hm6 Wed Oct 14 11:06:35 2015 : Debug: [ldap1] expand: %{Stripped-User-Name} -> hm6 Wed Oct 14 11:06:35 2015 : Debug: [ldap1] expand: (uid=%{%{Stripped-User-Name}:-%{User-Name}}) -> (uid=hm6) Wed Oct 14 11:06:35 2015 : Debug: [ldap1] expand: dc=rice,dc=edu -> dc=rice,dc=edu Wed Oct 14 11:06:35 2015 : Debug: [ldap1] checking if remote access for hm6 is allowed by riceClass Wed Oct 14 11:06:35 2015 : Debug: [ldap1] looking for check items in directory... Wed Oct 14 11:06:35 2015 : Debug: [ldap1] looking for reply items in directory... Wed Oct 14 11:06:35 2015 : Debug: [ldap1] user hm6 authorized to use remote access Wed Oct 14 11:06:35 2015 : Debug: +++[ldap1] = ok Wed Oct 14 11:06:35 2015 : Debug: ++} # redundant-load-balance group redundant_ldap = ok Wed Oct 14 11:06:35 2015 : Debug: ++? if (reply:Connect-Info =~ /[a-z]* student/) Wed Oct 14 11:06:35 2015 : Debug: ? Evaluating (reply:Connect-Info =~ /[a-z]* student/) -> TRUE Wed Oct 14 11:06:35 2015 : Debug: ++? if (reply:Connect-Info =~ /[a-z]* student/) -> TRUE Wed Oct 14 11:06:35 2015 : Debug: ++if (reply:Connect-Info =~ /[a-z]* student/) { Wed Oct 14 11:06:35 2015 : Debug: +++update reply { Wed Oct 14 11:06:35 2015 : Debug: +++} # update reply = noop Wed Oct 14 11:06:35 2015 : Debug: ++} # if (reply:Connect-Info =~ /[a-z]* student/) = noop Wed Oct 14 11:06:35 2015 : Debug: ++ ... skipping elsif for request 9057483: Preceding "if" was taken Wed Oct 14 11:06:35 2015 : Debug: ++ ... skipping elsif for request 9057483: Preceding "if" was taken Wed Oct 14 11:06:35 2015 : Debug: ++ ... skipping elsif for request 9057483: Preceding "if" was taken Wed Oct 14 11:06:35 2015 : Debug: ++? if ((Hint == "JOINstudent" ) && (reply:Connect-Info == "staff")) Wed Oct 14 11:06:35 2015 : Debug: (Attribute Hint was not found) Wed Oct 14 11:06:35 2015 : Debug: ?? Evaluating (Hint == "JOINstudent" ) -> FALSE Wed Oct 14 11:06:35 2015 : Debug: ?? Skipping (reply:Connect-Info == "staff") Wed Oct 14 11:06:35 2015 : Debug: ++? if ((Hint == "JOINstudent" ) && (reply:Connect-Info == "staff")) -> FALSE Wed Oct 14 11:06:35 2015 : Debug: ++[perl] = updated Wed Oct 14 11:06:35 2015 : Debug: ++update reply { Wed Oct 14 11:06:35 2015 : Debug: expand: %{reply:Tunnel-Private-Group-Id} -> student Wed Oct 14 11:06:35 2015 : Debug: ++} # update reply = noop Wed Oct 14 11:06:35 2015 : Debug: ++[expiration] = noop Wed Oct 14 11:06:35 2015 : Debug: ++[logintime] = noop Wed Oct 14 11:06:35 2015 : Debug: ++[pap] = noop Wed Oct 14 11:06:35 2015 : Debug: +} # group authorize = updated Wed Oct 14 11:06:35 2015 : Debug: Found Auth-Type = EAP Wed Oct 14 11:06:35 2015 : Debug: # Executing group from file /etc/opt/freeradius/sites-enabled/inner-tunnel Wed Oct 14 11:06:35 2015 : Debug: +group authenticate { Wed Oct 14 11:06:35 2015 : Debug: [eap] Request found, released from the list Wed Oct 14 11:06:35 2015 : Debug: [eap] EAP/mschapv2 Wed Oct 14 11:06:35 2015 : Debug: [eap] processing type mschapv2 Wed Oct 14 11:06:35 2015 : Debug: [eap] Freeing handler Wed Oct 14 11:06:35 2015 : Debug: ++[eap] = ok Wed Oct 14 11:06:35 2015 : Debug: +} # group authenticate = ok Wed Oct 14 11:06:35 2015 : Debug: # Executing section post-auth from file /etc/opt/freeradius/sites-enabled/inner-tunnel Wed Oct 14 11:06:35 2015 : Debug: +group post-auth { Wed Oct 14 11:06:35 2015 : Debug: [reply_log] expand: /var/opt/freeradius/radacct/%{Client-IP-Address}/reply-detail-%Y%m%d -> /var/opt/freeradius/radacct/10.64.76.100/reply-detail-20151014 Wed Oct 14 11:06:35 2015 : Debug: [reply_log] /var/opt/freeradius/radacct/%{Client-IP-Address}/reply-detail-%Y%m%d expands to /var/opt/freeradius/radacct/10.64.76.100/reply-detail-20151014 Wed Oct 14 11:06:35 2015 : Debug: [reply_log] expand: %t -> Wed Oct 14 11:06:35 2015 Wed Oct 14 11:06:35 2015 : Debug: ++[reply_log] = ok Wed Oct 14 11:06:35 2015 : Debug: ++update outer.reply { Wed Oct 14 11:06:35 2015 : Debug: expand: %{request:User-Name} -> hm6 Wed Oct 14 11:06:35 2015 : Debug: ++} # update outer.reply = noop Wed Oct 14 11:06:35 2015 : Debug: ++? if (! reply:Cached-Session-Policy) Wed Oct 14 11:06:35 2015 : Debug: ? Evaluating !(reply:Cached-Session-Policy) -> TRUE Wed Oct 14 11:06:35 2015 : Debug: ++? if (! reply:Cached-Session-Policy) -> TRUE Wed Oct 14 11:06:35 2015 : Debug: ++if (! reply:Cached-Session-Policy) { Wed Oct 14 11:06:35 2015 : Debug: +++update reply { Wed Oct 14 11:06:35 2015 : Debug: expand: TPG=%{reply:Tunnel-Private-Group-Id},CI=%{reply:Connect-Info} -> TPG=student,CI=student Wed Oct 14 11:06:35 2015 : Debug: +++} # update reply = noop Wed Oct 14 11:06:35 2015 : Debug: ++} # if (! reply:Cached-Session-Policy) = noop Wed Oct 14 11:06:35 2015 : Debug: +} # group post-auth = ok Wed Oct 14 11:06:35 2015 : Debug: [peap] Tunneled authentication was successful. Wed Oct 14 11:06:35 2015 : Debug: [peap] SUCCESS Wed Oct 14 11:06:35 2015 : Debug: [peap] Saving tunneled attributes for later Wed Oct 14 11:06:35 2015 : Debug: ++[eap] = handled Wed Oct 14 11:06:35 2015 : Debug: +} # group authenticate = handled Wed Oct 14 11:06:35 2015 : Debug: Sending Access-Challenge packet to host 10.64.76.100 port 32770, id=255, length=0 Wed Oct 14 11:06:35 2015 : Debug: User-Name = "hm6" Wed Oct 14 11:06:35 2015 : Debug: EAP-Message = 0x010d002b19001703010020d68d7d314369e1b1dc19347c66be477be80485fabcfcc62f6e6e489eea754605 Wed Oct 14 11:06:35 2015 : Debug: Message-Authenticator = 0x00000000000000000000000000000000 Wed Oct 14 11:06:35 2015 : Debug: State = 0x73e0c7cb78eddea1ed6477b7b8d8584b Wed Oct 14 11:06:35 2015 : Debug: Finished request 9057483. Wed Oct 14 11:06:35 2015 : Debug: Received Access-Request packet from host 10.64.76.100 port 32770, id=0, length=338 Wed Oct 14 11:06:35 2015 : Debug: User-Name = "hm6" Wed Oct 14 11:06:35 2015 : Debug: Chargeable-User-Identity = "" Wed Oct 14 11:06:35 2015 : Debug: Location-Capable = Civix-Location Wed Oct 14 11:06:35 2015 : Debug: Calling-Station-Id = "14-99-e2-bf-24-70" Wed Oct 14 11:06:35 2015 : Debug: Called-Station-Id = "00-23-eb-2e-3d-f0:Rice Owls" Wed Oct 14 11:06:35 2015 : Debug: NAS-Port = 13 Wed Oct 14 11:06:35 2015 : Debug: Cisco-AVPair = "audit-session-id=0a404c640127a12a561e621e" Wed Oct 14 11:06:35 2015 : Debug: Acct-Session-Id = "561e621e/14:99:e2:bf:24:70/10398428" Wed Oct 14 11:06:35 2015 : Debug: Cisco-AVPair = "mDNS=true" Wed Oct 14 11:06:35 2015 : Debug: NAS-IP-Address = 10.64.76.100 Wed Oct 14 11:06:35 2015 : Debug: NAS-Identifier = "WiSM2-HA1-1" Wed Oct 14 11:06:35 2015 : Debug: Airespace-Wlan-Id = 1 Wed Oct 14 11:06:35 2015 : Debug: Service-Type = Framed-User Wed Oct 14 11:06:35 2015 : Debug: Framed-MTU = 1300 Wed Oct 14 11:06:35 2015 : Debug: NAS-Port-Type = Wireless-802.11 Wed Oct 14 11:06:35 2015 : Debug: Tunnel-Type:0 = VLAN Wed Oct 14 11:06:35 2015 : Debug: Tunnel-Medium-Type:0 = IEEE-802 Wed Oct 14 11:06:35 2015 : Debug: Tunnel-Private-Group-Id:0 = "345" Wed Oct 14 11:06:35 2015 : Debug: EAP-Message = 0x020d002b190017030100207fe9dd32300c88353767ed4bffbab3e279fa3258403e2f50d7e8a4a286124c91 Wed Oct 14 11:06:35 2015 : Debug: State = 0x73e0c7cb78eddea1ed6477b7b8d8584b Wed Oct 14 11:06:35 2015 : Debug: Message-Authenticator = 0x7f3735fa881fa91fe2550706f3825d88 Wed Oct 14 11:06:35 2015 : Debug: # Executing section authorize from file /etc/opt/freeradius/sites-enabled/default Wed Oct 14 11:06:35 2015 : Debug: +group authorize { Wed Oct 14 11:06:35 2015 : Debug: ++[preprocess] = ok Wed Oct 14 11:06:35 2015 : Debug: ++[chap] = noop Wed Oct 14 11:06:35 2015 : Debug: ++[mschap] = noop Wed Oct 14 11:06:35 2015 : Debug: ++[digest] = noop Wed Oct 14 11:06:35 2015 : Debug: [suffix] No '@' in User-Name = "hm6", looking up realm NULL Wed Oct 14 11:06:35 2015 : Debug: [suffix] Found realm "NULL" Wed Oct 14 11:06:35 2015 : Debug: [suffix] Adding Stripped-User-Name = "hm6" Wed Oct 14 11:06:35 2015 : Debug: [suffix] Adding Realm = "NULL" Wed Oct 14 11:06:35 2015 : Debug: [suffix] Authentication realm is LOCAL. Wed Oct 14 11:06:35 2015 : Debug: ++[suffix] = ok Wed Oct 14 11:06:35 2015 : Debug: ++? if (Realm =~ /wlan.*gppnetwork\.org/) Wed Oct 14 11:06:35 2015 : Debug: ? Evaluating (Realm =~ /wlan.*gppnetwork\.org/) -> FALSE Wed Oct 14 11:06:35 2015 : Debug: ++? if (Realm =~ /wlan.*gppnetwork\.org/) -> FALSE Wed Oct 14 11:06:35 2015 : Debug: ++? if (Realm == "WiFi.sktelecom.com") Wed Oct 14 11:06:35 2015 : Debug: ? Evaluating (Realm == "WiFi.sktelecom.com") -> FALSE Wed Oct 14 11:06:35 2015 : Debug: ++? if (Realm == "WiFi.sktelecom.com") -> FALSE Wed Oct 14 11:06:35 2015 : Debug: [eap] EAP packet type response id 13 length 43 Wed Oct 14 11:06:35 2015 : Debug: [eap] Continuing tunnel setup. Wed Oct 14 11:06:35 2015 : Debug: ++[eap] = ok Wed Oct 14 11:06:35 2015 : Debug: +} # group authorize = ok Wed Oct 14 11:06:35 2015 : Debug: Found Auth-Type = EAP Wed Oct 14 11:06:35 2015 : Debug: # Executing group from file /etc/opt/freeradius/sites-enabled/default Wed Oct 14 11:06:35 2015 : Debug: +group authenticate { Wed Oct 14 11:06:35 2015 : Debug: [eap] Request found, released from the list Wed Oct 14 11:06:35 2015 : Debug: [eap] EAP/peap Wed Oct 14 11:06:35 2015 : Debug: [eap] processing type peap Wed Oct 14 11:06:35 2015 : Debug: [peap] processing EAP-TLS Wed Oct 14 11:06:35 2015 : Debug: [peap] eaptls_verify returned 7 Wed Oct 14 11:06:35 2015 : Debug: [peap] Done initial handshake Wed Oct 14 11:06:35 2015 : Debug: [peap] eaptls_process returned 7 Wed Oct 14 11:06:35 2015 : Debug: [peap] EAPTLS_OK Wed Oct 14 11:06:35 2015 : Debug: [peap] Session established. Decoding tunneled attributes. Wed Oct 14 11:06:35 2015 : Debug: [peap] Peap state send tlv success Wed Oct 14 11:06:35 2015 : Debug: [peap] Received EAP-TLV response. Wed Oct 14 11:06:35 2015 : Debug: [peap] Success Wed Oct 14 11:06:35 2015 : Debug: [peap] Using saved attributes from the original Access-Accept Wed Oct 14 11:06:35 2015 : Debug: [peap] Saving response in the cache Wed Oct 14 11:06:35 2015 : Debug: [eap] Freeing handler Wed Oct 14 11:06:35 2015 : Debug: ++[eap] = ok Wed Oct 14 11:06:35 2015 : Debug: +} # group authenticate = ok Wed Oct 14 11:06:35 2015 : Debug: # Executing section post-auth from file /etc/opt/freeradius/sites-enabled/default Wed Oct 14 11:06:35 2015 : Debug: +group post-auth { Wed Oct 14 11:06:35 2015 : Debug: [reply_log] expand: /var/opt/freeradius/radacct/%{Client-IP-Address}/reply-detail-%Y%m%d -> /var/opt/freeradius/radacct/10.64.76.100/reply-detail-20151014 Wed Oct 14 11:06:35 2015 : Debug: [reply_log] /var/opt/freeradius/radacct/%{Client-IP-Address}/reply-detail-%Y%m%d expands to /var/opt/freeradius/radacct/10.64.76.100/reply-detail-20151014 Wed Oct 14 11:06:35 2015 : Debug: [reply_log] expand: %t -> Wed Oct 14 11:06:35 2015 Wed Oct 14 11:06:35 2015 : Debug: ++[reply_log] = ok Wed Oct 14 11:06:35 2015 : Debug: ++[exec] = noop Wed Oct 14 11:06:35 2015 : Debug: ++? if (reply:Cached-Session-Policy =~ /TPG=(.+),CI=(.+)/) Wed Oct 14 11:06:35 2015 : Debug: ? Evaluating (reply:Cached-Session-Policy =~ /TPG=(.+),CI=(.+)/) -> TRUE Wed Oct 14 11:06:35 2015 : Debug: ++? if (reply:Cached-Session-Policy =~ /TPG=(.+),CI=(.+)/) -> TRUE Wed Oct 14 11:06:35 2015 : Debug: ++if (reply:Cached-Session-Policy =~ /TPG=(.+),CI=(.+)/) { Wed Oct 14 11:06:35 2015 : Debug: +++update reply { Wed Oct 14 11:06:35 2015 : Debug: expand: %{1} -> student Wed Oct 14 11:06:35 2015 : Debug: expand: %{2} -> student Wed Oct 14 11:06:35 2015 : Debug: +++} # update reply = noop Wed Oct 14 11:06:35 2015 : Debug: ++} # if (reply:Cached-Session-Policy =~ /TPG=(.+),CI=(.+)/) = noop Wed Oct 14 11:06:35 2015 : Debug: +} # group post-auth = ok Wed Oct 14 11:06:35 2015 : Debug: Sending Access-Accept packet to host 10.64.76.100 port 32770, id=0, length=0 Wed Oct 14 11:06:35 2015 : Debug: Connect-Info = "student" Wed Oct 14 11:06:35 2015 : Debug: Tunnel-Medium-Type:0 = IEEE-802 Wed Oct 14 11:06:35 2015 : Debug: Tunnel-Type:0 = VLAN Wed Oct 14 11:06:35 2015 : Debug: Tunnel-Private-Group-Id:0 = "student" Wed Oct 14 11:06:35 2015 : Debug: User-Name = "hm6" Wed Oct 14 11:06:35 2015 : Debug: Cached-Session-Policy = "TPG=student,CI=student" Wed Oct 14 11:06:35 2015 : Debug: MS-MPPE-Recv-Key = 0xd6fc61507727f965242767e2951fa31390772d22397eda27f20ad3eda77f17f0 Wed Oct 14 11:06:35 2015 : Debug: MS-MPPE-Send-Key = 0x0a3aeaa6bd45ca7c59120616d94d8bbbde1a3bd3584aa1c747317378d29f2abc Wed Oct 14 11:06:35 2015 : Debug: EAP-MSK = 0xd6fc61507727f965242767e2951fa31390772d22397eda27f20ad3eda77f17f00a3aeaa6bd45ca7c59120616d94d8bbbde1a3bd3584aa1c747317378d29f2abc Wed Oct 14 11:06:35 2015 : Debug: EAP-EMSK = 0xc871c16e062585ab146537669c11f929e0dc78daf334f1796eddebe6052822f0093f71095873686c05bb1612d3d76aa1cbbde9ddd33be02e428862a6e80ef16f Wed Oct 14 11:06:35 2015 : Debug: EAP-Session-Id = 0x19561e7d8ceb6b159381eb964528005513132c4b913cf9958ac64937c507e97740561e7d8be4a39e0ba6cd482c0f70ec79000e3385cfbfb6217470e77130ee8d1e Wed Oct 14 11:06:35 2015 : Debug: EAP-Message = 0x030d0004 Wed Oct 14 11:06:35 2015 : Debug: Message-Authenticator = 0x00000000000000000000000000000000 Wed Oct 14 11:06:35 2015 : Debug: Finished request 9057486. Wed Oct 14 11:06:35 2015 : Debug: Received Accounting-Request packet from host 10.64.76.100 port 32770, id=131, length=281 Wed Oct 14 11:06:35 2015 : Debug: User-Name = "hm6" Wed Oct 14 11:06:35 2015 : Debug: NAS-Port = 13 Wed Oct 14 11:06:35 2015 : Debug: NAS-IP-Address = 10.64.76.100 Wed Oct 14 11:06:35 2015 : Debug: Framed-IP-Address = 10.116.79.74 Wed Oct 14 11:06:35 2015 : Debug: NAS-Identifier = "WiSM2-HA1-1" Wed Oct 14 11:06:35 2015 : Debug: Airespace-Wlan-Id = 1 Wed Oct 14 11:06:35 2015 : Debug: Acct-Session-Id = "561e621e/14:99:e2:bf:24:70/10398428" Wed Oct 14 11:06:35 2015 : Debug: NAS-Port-Type = Wireless-802.11 Wed Oct 14 11:06:35 2015 : Debug: Cisco-AVPair = "audit-session-id=0a404c640127a12a561e621e" Wed Oct 14 11:06:35 2015 : Debug: Acct-Authentic = RADIUS Wed Oct 14 11:06:35 2015 : Debug: Tunnel-Type:0 = VLAN Wed Oct 14 11:06:35 2015 : Debug: Tunnel-Medium-Type:0 = IEEE-802 Wed Oct 14 11:06:35 2015 : Debug: Tunnel-Private-Group-Id:0 = "343" Wed Oct 14 11:06:35 2015 : Debug: Event-Timestamp = "Oct 14 2015 11:06:35 CDT" Wed Oct 14 11:06:35 2015 : Debug: Acct-Status-Type = Interim-Update Wed Oct 14 11:06:35 2015 : Debug: Acct-Input-Octets = 4472429 Wed Oct 14 11:06:35 2015 : Debug: Acct-Input-Gigawords = 0 Wed Oct 14 11:06:35 2015 : Debug: Acct-Output-Octets = 4299801 Wed Oct 14 11:06:35 2015 : Debug: Acct-Output-Gigawords = 0 Wed Oct 14 11:06:35 2015 : Debug: Acct-Input-Packets = 52431 Wed Oct 14 11:06:35 2015 : Debug: Acct-Output-Packets = 34784 Wed Oct 14 11:06:35 2015 : Debug: Acct-Session-Time = 7014 Wed Oct 14 11:06:35 2015 : Debug: Acct-Delay-Time = 0 Wed Oct 14 11:06:35 2015 : Debug: Calling-Station-Id = "14-99-e2-bf-24-70" Wed Oct 14 11:06:35 2015 : Debug: Called-Station-Id = "6c-20-56-2c-20-80" Wed Oct 14 11:06:35 2015 : Debug: # Executing section preacct from file /etc/opt/freeradius/sites-enabled/default Wed Oct 14 11:06:35 2015 : Debug: +group preacct { Wed Oct 14 11:06:35 2015 : Debug: ++[preprocess] = ok Wed Oct 14 11:06:35 2015 : Debug: [acct_unique] Hashing 'NAS-Port = 13,NAS-Identifier = "WiSM2-HA1-1",NAS-IP-Address = 10.64.76.100,Acct-Session-Id = "561e621e/14:99:e2:bf:24:70/10398428",User-Name = "hm6"' Wed Oct 14 11:06:35 2015 : Debug: [acct_unique] Acct-Unique-Session-ID = "d8afff7ef8dc3708". Wed Oct 14 11:06:35 2015 : Debug: ++[acct_unique] = ok Wed Oct 14 11:06:35 2015 : Debug: [suffix] No '@' in User-Name = "hm6", looking up realm NULL Wed Oct 14 11:06:35 2015 : Debug: [suffix] Found realm "NULL" Wed Oct 14 11:06:35 2015 : Debug: [suffix] Adding Stripped-User-Name = "hm6" Wed Oct 14 11:06:35 2015 : Debug: [suffix] Adding Realm = "NULL" Wed Oct 14 11:06:35 2015 : Debug: [suffix] Accounting realm is LOCAL. Wed Oct 14 11:06:35 2015 : Debug: ++[suffix] = ok Wed Oct 14 11:06:35 2015 : Debug: ++[files] = noop Wed Oct 14 11:06:35 2015 : Debug: +} # group preacct = ok Wed Oct 14 11:06:35 2015 : Debug: # Executing section accounting from file /etc/opt/freeradius/sites-enabled/default Wed Oct 14 11:06:35 2015 : Debug: +group accounting { Wed Oct 14 11:06:35 2015 : Debug: [detail] expand: /var/opt/freeradius/radacct/%{Client-IP-Address}/detail-%Y%m%d -> /var/opt/freeradius/radacct/10.64.76.100/detail-20151014 Wed Oct 14 11:06:35 2015 : Debug: [detail] /var/opt/freeradius/radacct/%{Client-IP-Address}/detail-%Y%m%d expands to /var/opt/freeradius/radacct/10.64.76.100/detail-20151014 Wed Oct 14 11:06:35 2015 : Debug: [detail] expand: %t -> Wed Oct 14 11:06:35 2015 Wed Oct 14 11:06:35 2015 : Debug: ++[detail] = ok Wed Oct 14 11:06:35 2015 : Debug: ++[unix] = noop Wed Oct 14 11:06:35 2015 : Debug: [radutmp] expand: /var/opt/freeradius/radutmp -> /var/opt/freeradius/radutmp Wed Oct 14 11:06:35 2015 : Debug: [radutmp] expand: %{User-Name} -> hm6 Wed Oct 14 11:06:35 2015 : Debug: ++[radutmp] = ok Wed Oct 14 11:06:35 2015 : Debug: ++[exec] = noop Wed Oct 14 11:06:35 2015 : Debug: [attr_filter.accounting_response] expand: %{User-Name} -> hm6 Wed Oct 14 11:06:35 2015 : Debug: ++[attr_filter.accounting_response] = updated Wed Oct 14 11:06:35 2015 : Debug: +} # group accounting = updated Wed Oct 14 11:06:35 2015 : Debug: Sending Accounting-Response packet to host 10.64.76.100 port 32770, id=131, length=0 Wed Oct 14 11:06:35 2015 : Debug: Finished request 9057490. Wed Oct 14 11:06:36 2015 : Debug: Cleaning up request 9057490 ID 131 with timestamp +105162 Wed Oct 14 11:06:37 2015 : Debug: Cleaning up request 9057415 ID 207 with timestamp +105162 Wed Oct 14 11:06:37 2015 : Debug: Cleaning up request 9057420 ID 209 with timestamp +105162 Wed Oct 14 11:06:37 2015 : Debug: Cleaning up request 9057421 ID 210 with timestamp +105162 Wed Oct 14 11:06:37 2015 : Debug: Cleaning up request 9057422 ID 211 with timestamp +105162 Wed Oct 14 11:06:37 2015 : Debug: Cleaning up request 9057425 ID 213 with timestamp +105162 Wed Oct 14 11:06:37 2015 : Debug: Cleaning up request 9057429 ID 216 with timestamp +105162 Wed Oct 14 11:06:37 2015 : Debug: Cleaning up request 9057431 ID 218 with timestamp +105162 Wed Oct 14 11:06:37 2015 : Debug: Cleaning up request 9057460 ID 242 with timestamp +105162 Wed Oct 14 11:06:37 2015 : Debug: Cleaning up request 9057464 ID 245 with timestamp +105162 Wed Oct 14 11:06:37 2015 : Debug: Cleaning up request 9057465 ID 246 with timestamp +105162 Wed Oct 14 11:06:37 2015 : Debug: Cleaning up request 9057467 ID 248 with timestamp +105162 Wed Oct 14 11:06:38 2015 : Debug: Cleaning up request 9057483 ID 255 with timestamp +105162 Wed Oct 14 11:06:38 2015 : Debug: Cleaning up request 9057486 ID 0 with timestamp +105162