rad_recv: Access-Request packet from host 10.32.33.1 port 32769, id=150, length=199 User-Name = "nicholas_kartsioukas" Calling-Station-Id = "00-23-4e-ba-6b-f4" Called-Station-Id = "00-1a-a2-c1-2c-30:test" NAS-Port = 29 NAS-IP-Address = 10.32.33.1 NAS-Identifier = "slo-wlc-1" Airespace-Wlan-Id = 5 Service-Type = Framed-User Framed-MTU = 1300 NAS-Port-Type = Wireless-802.11 Tunnel-Type:0 = VLAN Tunnel-Medium-Type:0 = IEEE-802 Tunnel-Private-Group-Id:0 = "17" EAP-Message = 0x02010019016e6963686f6c61735f6b61727473696f756b6173 Message-Authenticator = 0x71352edeaf671fac560216764d617e33 # Executing section authorize from file /etc/freeradius/sites-enabled/default +- entering group authorize {...} ++[preprocess] returns ok [auth_log] expand: /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/freeradius/radacct/10.32.33.1/auth-detail-20110714 [auth_log] /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/10.32.33.1/auth-detail-20110714 [auth_log] expand: %t -> Thu Jul 14 16:45:34 2011 ++[auth_log] returns ok ++- entering policy rewrite_called_station_id {...} +++? if (Called-Station-Id =~ /^([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:]?([-a-z0-9_.]*)?/i) ? Evaluating (Called-Station-Id =~ /^([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:]?([-a-z0-9_.]*)?/i) -> TRUE +++? if (Called-Station-Id =~ /^([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:]?([-a-z0-9_.]*)?/i) -> TRUE +++- entering if (Called-Station-Id =~ /^([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:]?([-a-z0-9_.]*)?/i) {...} expand: %{1}%{2}%{3}%{4}%{5}%{6} -> 001aa2c12c30 expand: %{7} -> test ++++[request] returns ok +++- if (Called-Station-Id =~ /^([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:]?([-a-z0-9_.]*)?/i) returns ok +++ ... skipping else for request 0: Preceding "if" was taken ++- policy rewrite_called_station_id returns ok ++- entering switch Called-Station-Ssid {...} +++- entering case test {...} ++++- entering redundant-load-balance group redundant-load-balance {...} [ldap_parrotfish] performing user authorization for nicholas_kartsioukas [ldap_parrotfish] expand: %{Stripped-User-Name} -> [ldap_parrotfish] ... expanding second conditional [ldap_parrotfish] expand: %{User-Name} -> nicholas_kartsioukas [ldap_parrotfish] expand: (sAMAccountName=%{%{Stripped-User-Name}:-%{User-Name}}) -> (sAMAccountName=nicholas_kartsioukas) [ldap_parrotfish] expand: ou=CUESTA,dc=cuesta,dc=org -> ou=CUESTA,dc=cuesta,dc=org [ldap_parrotfish] ldap_get_conn: Checking Id: 0 [ldap_parrotfish] ldap_get_conn: Got Id: 0 [ldap_parrotfish] attempting LDAP reconnection [ldap_parrotfish] (re)connect to parrotfish.cuesta.org:389, authentication 0 [ldap_parrotfish] starting TLS [ldap_parrotfish] bind as freeradius@cuesta.org/* to parrotfish.cuesta.org:389 [ldap_parrotfish] waiting for bind result ... [ldap_parrotfish] Bind was successful [ldap_parrotfish] performing search in ou=CUESTA,dc=cuesta,dc=org, with filter (sAMAccountName=nicholas_kartsioukas) [ldap_parrotfish] No default NMAS login sequence [ldap_parrotfish] looking for check items in directory... [ldap_parrotfish] looking for reply items in directory... WARNING: No "known good" password was found in LDAP. Are you sure that the user is configured correctly? [ldap_parrotfish] user nicholas_kartsioukas authorized to use remote access [ldap_parrotfish] ldap_release_conn: Release Id: 0 +++++[ldap_parrotfish] returns ok ++++- redundant-load-balance group redundant-load-balance returns ok ++++[control] returns ok +++- case test returns ok ++- switch Called-Station-Ssid returns ok ++[files] returns noop ++[expiration] returns noop ++[logintime] returns noop Found Auth-Type = CUESTA # Executing group from file /etc/freeradius/sites-enabled/default +- entering group CUESTA {...} [eap_cuesta] EAP Identity [eap_cuesta] processing type tls [tls] Initiate [tls] Start returned 1 ++[eap_cuesta] returns handled Sending Access-Challenge of id 150 to 10.32.33.1 port 32769 EAP-Message = 0x010200061920 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x75706a9e757273896627c624035ec732 Finished request 0. Going to the next request Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 10.32.33.1 port 32769, id=150, length=199 Sending duplicate reply to client slo-wlc1 port 32769 - ID: 150 Sending Access-Challenge of id 150 to 10.32.33.1 port 32769 Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 10.32.33.1 port 32769, id=150, length=199 Sending duplicate reply to client slo-wlc1 port 32769 - ID: 150 Sending Access-Challenge of id 150 to 10.32.33.1 port 32769 Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 10.32.33.1 port 32769, id=151, length=297 User-Name = "nicholas_kartsioukas" Calling-Station-Id = "00-23-4e-ba-6b-f4" Called-Station-Id = "00-1a-a2-c1-2c-30:test" NAS-Port = 29 NAS-IP-Address = 10.32.33.1 NAS-Identifier = "slo-wlc-1" Airespace-Wlan-Id = 5 Service-Type = Framed-User Framed-MTU = 1300 NAS-Port-Type = Wireless-802.11 Tunnel-Type:0 = VLAN Tunnel-Medium-Type:0 = IEEE-802 Tunnel-Private-Group-Id:0 = "17" EAP-Message = 0x0202006919800000005f160301005a0100005603014e1f7f8a9e8a79e82f85c4c8e07ff243e04120a7000329ada58154f7122c828f00002800390038003500160013000a00330032002f000500040015001200090014001100080006000300ff020100000400230000 State = 0x75706a9e757273896627c624035ec732 Message-Authenticator = 0xbbfe0d61df31168f1f0da3b1fbb4960e # Executing section authorize from file /etc/freeradius/sites-enabled/default +- entering group authorize {...} ++[preprocess] returns ok [auth_log] expand: /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/freeradius/radacct/10.32.33.1/auth-detail-20110714 [auth_log] /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/10.32.33.1/auth-detail-20110714 [auth_log] expand: %t -> Thu Jul 14 16:45:39 2011 ++[auth_log] returns ok ++- entering policy rewrite_called_station_id {...} +++? if (Called-Station-Id =~ /^([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:]?([-a-z0-9_.]*)?/i) ? Evaluating (Called-Station-Id =~ /^([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:]?([-a-z0-9_.]*)?/i) -> TRUE +++? if (Called-Station-Id =~ /^([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:]?([-a-z0-9_.]*)?/i) -> TRUE +++- entering if (Called-Station-Id =~ /^([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:]?([-a-z0-9_.]*)?/i) {...} expand: %{1}%{2}%{3}%{4}%{5}%{6} -> 001aa2c12c30 expand: %{7} -> test ++++[request] returns ok +++- if (Called-Station-Id =~ /^([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:]?([-a-z0-9_.]*)?/i) returns ok +++ ... skipping else for request 1: Preceding "if" was taken ++- policy rewrite_called_station_id returns ok ++- entering switch Called-Station-Ssid {...} +++- entering case test {...} ++++- entering redundant-load-balance group redundant-load-balance {...} [ldap_prawn] performing user authorization for nicholas_kartsioukas [ldap_prawn] expand: %{Stripped-User-Name} -> [ldap_prawn] ... expanding second conditional [ldap_prawn] expand: %{User-Name} -> nicholas_kartsioukas [ldap_prawn] expand: (sAMAccountName=%{%{Stripped-User-Name}:-%{User-Name}}) -> (sAMAccountName=nicholas_kartsioukas) [ldap_prawn] expand: ou=CUESTA,dc=cuesta,dc=org -> ou=CUESTA,dc=cuesta,dc=org [ldap_prawn] ldap_get_conn: Checking Id: 0 [ldap_prawn] ldap_get_conn: Got Id: 0 [ldap_prawn] attempting LDAP reconnection [ldap_prawn] (re)connect to prawn.cuesta.org:389, authentication 0 [ldap_prawn] starting TLS [ldap_prawn] bind as freeradius@cuesta.org/* to prawn.cuesta.org:389 [ldap_prawn] waiting for bind result ... [ldap_prawn] Bind was successful [ldap_prawn] performing search in ou=CUESTA,dc=cuesta,dc=org, with filter (sAMAccountName=nicholas_kartsioukas) [ldap_prawn] No default NMAS login sequence [ldap_prawn] looking for check items in directory... [ldap_prawn] looking for reply items in directory... WARNING: No "known good" password was found in LDAP. Are you sure that the user is configured correctly? [ldap_prawn] user nicholas_kartsioukas authorized to use remote access [ldap_prawn] ldap_release_conn: Release Id: 0 +++++[ldap_prawn] returns ok ++++- redundant-load-balance group redundant-load-balance returns ok ++++[control] returns ok +++- case test returns ok ++- switch Called-Station-Ssid returns ok ++[files] returns noop ++[expiration] returns noop ++[logintime] returns noop Found Auth-Type = CUESTA # Executing group from file /etc/freeradius/sites-enabled/default +- entering group CUESTA {...} [eap_cuesta] Request found, released from the list [eap_cuesta] EAP/peap [eap_cuesta] processing type peap [peap] processing EAP-TLS TLS Length 95 [peap] Length Included [peap] eaptls_verify returned 11 [peap] (other): before/accept initialization [peap] TLS_accept: before/accept initialization [peap] <<< TLS 1.0 Handshake [length 005a], ClientHello [peap] TLS_accept: SSLv3 read client hello A [peap] >>> TLS 1.0 Handshake [length 0031], ServerHello [peap] TLS_accept: SSLv3 write server hello A [peap] >>> TLS 1.0 Handshake [length 0c9e], Certificate [peap] TLS_accept: SSLv3 write certificate A [peap] >>> TLS 1.0 Handshake [length 020d], ServerKeyExchange [peap] TLS_accept: SSLv3 write key exchange A [peap] >>> TLS 1.0 Handshake [length 0004], ServerHelloDone [peap] TLS_accept: SSLv3 write server done A [peap] TLS_accept: SSLv3 flush data [peap] TLS_accept: Need to read more data: SSLv3 read client certificate A In SSL Handshake Phase In SSL Accept mode [peap] eaptls_process returned 13 [peap] EAPTLS_HANDLED ++[eap_cuesta] returns handled Sending Access-Challenge of id 151 to 10.32.33.1 port 32769 EAP-Message = 0x0103040019c000000ef416030100310200002d03014e1f7fa347c0c3d6c892fe299cd75ca3aa2c544061c32bd3272d526d7b55ff06000039010005ff010001001603010c9e0b000c9a000c970003fa308203f6308202dea003020102021022fe7e14527a08952ff9ef9c52bf4145300d06092a864886f70d0101050500303c310b300906035504061302555331153013060355040a130c5468617774652c20496e632e311630140603550403130d5468617774652053534c204341301e170d3131303532353030303030305a170d3132303632303233353935395a30818e310b3009060355040613025553311330110603550408130a43616c69666f72 EAP-Message = 0x6e6961311830160603550407140f53616e204c756973204f626973706f31173015060355040a140e43756573746120436f6c6c656765311a3018060355040b1411436f6d7075746572205365727669636573311b301906035504031412776562617574682e6375657374612e65647530820122300d06092a864886f70d01010105000382010f003082010a02820101009f15ff8560f97eecdd587411089166fd4cb7912243e7ef749efa0042711c51a4760be3f12c8040b732c74d9fd61f98488856931be1c7a7e9dd4cde8ea880ff6c987d616f105b53364b27954b50fd0c819aea713f6c79f207f74608ea6e8dc078bf1933468da308aac820d20db5 EAP-Message = 0xbd6ec9241984e03b8b89498b7900460a68cc0fb3862c48cf373ec61bf8b00d164f8ac3a6de689e02791e6ca962f9ff240ebb1454aa5faf851adf5a8fa4165dda1dc9088dde24eece774a5b5a1378516c775a7adc9ebba4451ce521efdfc7a4a746bcf69f13fb849b1268ea08a9d4f848fea09c8f2b31254ee8539a4821b3bd80b8d0be8e038902862dc173f8a751ceadd698290203010001a381a030819d300c0603551d130101ff04023000303a0603551d1f04333031302fa02da02b8629687474703a2f2f7376722d6f762d63726c2e7468617774652e636f6d2f5468617774654f562e63726c301d0603551d250416301406082b06010505070301 EAP-Message = 0x06082b06010505070302303206082b0601050507010104263024302206082b060105050730018616687474703a2f2f6f6373702e7468617774652e636f6d300d06092a864886f70d0101050500038201010045eaf219ea3a1fa6c09d0ee57c85150014266321401baa5bd7c2d4dc9cbbcb2f2185f79aafc84002be5d69fa756a90e3c86e939a126e52264eec048b2e504766202bc98b579d9e5ea1282ba64fff433703df9f516dbd70061663c1dda87a77e2b322c7a41e92fe95230f640dd325fa507e2cfd866f0fd38c1c669f172bbd7da6f5cd68e9ec7bd4b14f1f1c84fe7eb04d53323b3363e8885ac0245a9cc10f764c08005c645236691b98cd7e EAP-Message = 0x9e5989b2aa987714d0fddc68 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x75706a9e747373896627c624035ec732 Finished request 1. Going to the next request Waking up in 4.7 seconds. rad_recv: Access-Request packet from host 10.32.33.1 port 32769, id=152, length=198 User-Name = "nicholas_kartsioukas" Calling-Station-Id = "00-23-4e-ba-6b-f4" Called-Station-Id = "00-1a-a2-c1-2c-30:test" NAS-Port = 29 NAS-IP-Address = 10.32.33.1 NAS-Identifier = "slo-wlc-1" Airespace-Wlan-Id = 5 Service-Type = Framed-User Framed-MTU = 1300 NAS-Port-Type = Wireless-802.11 Tunnel-Type:0 = VLAN Tunnel-Medium-Type:0 = IEEE-802 Tunnel-Private-Group-Id:0 = "17" EAP-Message = 0x020300061900 State = 0x75706a9e747373896627c624035ec732 Message-Authenticator = 0xdca4b4fbaf85ea5fa2866a6aa06b93de # Executing section authorize from file /etc/freeradius/sites-enabled/default +- entering group authorize {...} ++[preprocess] returns ok [auth_log] expand: /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/freeradius/radacct/10.32.33.1/auth-detail-20110714 [auth_log] /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/10.32.33.1/auth-detail-20110714 [auth_log] expand: %t -> Thu Jul 14 16:45:39 2011 ++[auth_log] returns ok ++- entering policy rewrite_called_station_id {...} +++? if (Called-Station-Id =~ /^([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:]?([-a-z0-9_.]*)?/i) ? Evaluating (Called-Station-Id =~ /^([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:]?([-a-z0-9_.]*)?/i) -> TRUE +++? if (Called-Station-Id =~ /^([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:]?([-a-z0-9_.]*)?/i) -> TRUE +++- entering if (Called-Station-Id =~ /^([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:]?([-a-z0-9_.]*)?/i) {...} expand: %{1}%{2}%{3}%{4}%{5}%{6} -> 001aa2c12c30 expand: %{7} -> test ++++[request] returns ok +++- if (Called-Station-Id =~ /^([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:]?([-a-z0-9_.]*)?/i) returns ok +++ ... skipping else for request 2: Preceding "if" was taken ++- policy rewrite_called_station_id returns ok ++- entering switch Called-Station-Ssid {...} +++- entering case test {...} ++++- entering redundant-load-balance group redundant-load-balance {...} [ldap_prawn] performing user authorization for nicholas_kartsioukas [ldap_prawn] expand: %{Stripped-User-Name} -> [ldap_prawn] ... expanding second conditional [ldap_prawn] expand: %{User-Name} -> nicholas_kartsioukas [ldap_prawn] expand: (sAMAccountName=%{%{Stripped-User-Name}:-%{User-Name}}) -> (sAMAccountName=nicholas_kartsioukas) [ldap_prawn] expand: ou=CUESTA,dc=cuesta,dc=org -> ou=CUESTA,dc=cuesta,dc=org [ldap_prawn] ldap_get_conn: Checking Id: 0 [ldap_prawn] ldap_get_conn: Got Id: 0 [ldap_prawn] performing search in ou=CUESTA,dc=cuesta,dc=org, with filter (sAMAccountName=nicholas_kartsioukas) [ldap_prawn] No default NMAS login sequence [ldap_prawn] looking for check items in directory... [ldap_prawn] looking for reply items in directory... WARNING: No "known good" password was found in LDAP. Are you sure that the user is configured correctly? [ldap_prawn] user nicholas_kartsioukas authorized to use remote access [ldap_prawn] ldap_release_conn: Release Id: 0 +++++[ldap_prawn] returns ok ++++- redundant-load-balance group redundant-load-balance returns ok ++++[control] returns ok +++- case test returns ok ++- switch Called-Station-Ssid returns ok ++[files] returns noop ++[expiration] returns noop ++[logintime] returns noop Found Auth-Type = CUESTA # Executing group from file /etc/freeradius/sites-enabled/default +- entering group CUESTA {...} [eap_cuesta] Request found, released from the list [eap_cuesta] EAP/peap [eap_cuesta] processing type peap [peap] processing EAP-TLS [peap] Received TLS ACK [peap] ACK handshake fragment handler [peap] eaptls_verify returned 1 [peap] eaptls_process returned 13 [peap] EAPTLS_HANDLED ++[eap_cuesta] returns handled Sending Access-Challenge of id 152 to 10.32.33.1 port 32769 EAP-Message = 0x010403fc19401ab7c901f7cacc5dc99ee49a03ad3f7add0082f5ef21975afb68b7b500c0410af294a94801ae63e82746f1e02a752b0a58318447d1c5e8042cfa73eeaaffc6404dc4c3a435fe9859790004703082046c30820354a00302010202104d5f2c3408b24c20cd6d507e244dc9ec300d06092a864886f70d01010505003081a9310b300906035504061302555331153013060355040a130c7468617774652c20496e632e31283026060355040b131f43657274696669636174696f6e205365727669636573204469766973696f6e31383036060355040b132f2863292032303036207468617774652c20496e632e202d20466f7220617574686f EAP-Message = 0x72697a656420757365206f6e6c79311f301d06035504031316746861777465205072696d61727920526f6f74204341301e170d3130303230383030303030305a170d3230303230373233353935395a303c310b300906035504061302555331153013060355040a130c5468617774652c20496e632e311630140603550403130d5468617774652053534c20434130820122300d06092a864886f70d01010105000382010f003082010a028201010099e4855b76497d2f05d8c5acc8c8a9d3dc98e6d734a62f0cf22226d8a3c9144c8f05a445e8140c5890051ab7c5c106a580afbb1d496b523488c359e7ef6bc427418c2b661dd0e0a3979819344b41d5 EAP-Message = 0x98d5c705ada2e4d7ed0cad4fc1b5b021fd3e5053b2c490d0d430676c9af10e74c4c2dc8ae897ffc992ae018a560a9832b00023ec901a60c3edbb3acb0f639f0d44c952e12596bfed5095897f5614b1b7611d1c078c3a2cf7ff80de3945d5af1ad178d8c7716aa319a7325021e9f20ea1c613034448d166a85257d711b4938be5999f5de77851e54df6b759b476b509374d0638137a1c08985cc4484acb52a0a9f8b19d8e7b79b0202f3c96a8116247bb110203010001a381fb3081f8303206082b0601050507010104263024302206082b060105050730018616687474703a2f2f6f6373702e7468617774652e636f6d30120603551d130101ff040830 EAP-Message = 0x060101ff02010030340603551d1f042d302b3029a027a0258623687474703a2f2f63726c2e7468617774652e636f6d2f5468617774655043412e63726c300e0603551d0f0101ff04040302010630280603551d110421301fa41d301b3119301706035504031310566572695369676e4d504b492d322d39301d0603551d0e04160414a7a283bb3445403dfcd5304f12b93ea1019ff6db301f0603551d230418301680147b5b45cfafcecb7afd31921a6ab6f346eb574850300d06092a864886f70d01010505000382010100802280e06cc89516d7572687f37234dbc67256273ed396f62e2591a53e3397a74be52ffb257d2f0761fa6f83744c4c537220 EAP-Message = 0xa47acf5151568188 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x75706a9e777473896627c624035ec732 Finished request 2. Going to the next request Waking up in 4.6 seconds. rad_recv: Access-Request packet from host 10.32.33.1 port 32769, id=153, length=198 User-Name = "nicholas_kartsioukas" Calling-Station-Id = "00-23-4e-ba-6b-f4" Called-Station-Id = "00-1a-a2-c1-2c-30:test" NAS-Port = 29 NAS-IP-Address = 10.32.33.1 NAS-Identifier = "slo-wlc-1" Airespace-Wlan-Id = 5 Service-Type = Framed-User Framed-MTU = 1300 NAS-Port-Type = Wireless-802.11 Tunnel-Type:0 = VLAN Tunnel-Medium-Type:0 = IEEE-802 Tunnel-Private-Group-Id:0 = "17" EAP-Message = 0x020400061900 State = 0x75706a9e777473896627c624035ec732 Message-Authenticator = 0x06e4864afd3ce2bd7122f92c2025b76c # Executing section authorize from file /etc/freeradius/sites-enabled/default +- entering group authorize {...} ++[preprocess] returns ok [auth_log] expand: /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/freeradius/radacct/10.32.33.1/auth-detail-20110714 [auth_log] /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/10.32.33.1/auth-detail-20110714 [auth_log] expand: %t -> Thu Jul 14 16:45:39 2011 ++[auth_log] returns ok ++- entering policy rewrite_called_station_id {...} +++? if (Called-Station-Id =~ /^([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:]?([-a-z0-9_.]*)?/i) ? Evaluating (Called-Station-Id =~ /^([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:]?([-a-z0-9_.]*)?/i) -> TRUE +++? if (Called-Station-Id =~ /^([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:]?([-a-z0-9_.]*)?/i) -> TRUE +++- entering if (Called-Station-Id =~ /^([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:]?([-a-z0-9_.]*)?/i) {...} expand: %{1}%{2}%{3}%{4}%{5}%{6} -> 001aa2c12c30 expand: %{7} -> test ++++[request] returns ok +++- if (Called-Station-Id =~ /^([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:]?([-a-z0-9_.]*)?/i) returns ok +++ ... skipping else for request 3: Preceding "if" was taken ++- policy rewrite_called_station_id returns ok ++- entering switch Called-Station-Ssid {...} +++- entering case test {...} ++++- entering redundant-load-balance group redundant-load-balance {...} [ldap_prawn] performing user authorization for nicholas_kartsioukas [ldap_prawn] expand: %{Stripped-User-Name} -> [ldap_prawn] ... expanding second conditional [ldap_prawn] expand: %{User-Name} -> nicholas_kartsioukas [ldap_prawn] expand: (sAMAccountName=%{%{Stripped-User-Name}:-%{User-Name}}) -> (sAMAccountName=nicholas_kartsioukas) [ldap_prawn] expand: ou=CUESTA,dc=cuesta,dc=org -> ou=CUESTA,dc=cuesta,dc=org [ldap_prawn] ldap_get_conn: Checking Id: 0 [ldap_prawn] ldap_get_conn: Got Id: 0 [ldap_prawn] performing search in ou=CUESTA,dc=cuesta,dc=org, with filter (sAMAccountName=nicholas_kartsioukas) [ldap_prawn] No default NMAS login sequence [ldap_prawn] looking for check items in directory... [ldap_prawn] looking for reply items in directory... WARNING: No "known good" password was found in LDAP. Are you sure that the user is configured correctly? [ldap_prawn] user nicholas_kartsioukas authorized to use remote access [ldap_prawn] ldap_release_conn: Release Id: 0 +++++[ldap_prawn] returns ok ++++- redundant-load-balance group redundant-load-balance returns ok ++++[control] returns ok +++- case test returns ok ++- switch Called-Station-Ssid returns ok ++[files] returns noop ++[expiration] returns noop ++[logintime] returns noop Found Auth-Type = CUESTA # Executing group from file /etc/freeradius/sites-enabled/default +- entering group CUESTA {...} [eap_cuesta] Request found, released from the list [eap_cuesta] EAP/peap [eap_cuesta] processing type peap [peap] processing EAP-TLS [peap] Received TLS ACK [peap] ACK handshake fragment handler [peap] eaptls_verify returned 1 [peap] eaptls_process returned 13 [peap] EAPTLS_HANDLED ++[eap_cuesta] returns handled Sending Access-Challenge of id 153 to 10.32.33.1 port 32769 EAP-Message = 0x010503fc1940b06d1f362cc82bb18899c1fe44ab48517cd8f244642ad871a7fb1a2ff9198d34b223bfc44c551d8e44e8aa5d9add9ffd03c7ba24438d2d4744dbf6d898c8b2f9daefed295c6912fad123960fbf9c0df2794553379a562fe8571070f6ee890c49899ac123f5c22acc41cf22ab656eb794826d2f405f58deeb952ba672685219912aae759d4e92e6cade54ea18ab253ce664a6791f267d61ed7dd2e57155d893177c1438303cdf86e34cad49e39759ce1b9b2bcedc65d40b286b4e84465144f733082d589721ae0004243082042030820308a0030201020210344ed55720d5edec49f42fce37db2b6d300d06092a864886f70d0101050500 EAP-Message = 0x3081a9310b300906035504061302555331153013060355040a130c7468617774652c20496e632e31283026060355040b131f43657274696669636174696f6e205365727669636573204469766973696f6e31383036060355040b132f2863292032303036207468617774652c20496e632e202d20466f7220617574686f72697a656420757365206f6e6c79311f301d06035504031316746861777465205072696d61727920526f6f74204341301e170d3036313131373030303030305a170d3336303731363233353935395a3081a9310b300906035504061302555331153013060355040a130c7468617774652c20496e632e31283026060355040b13 EAP-Message = 0x1f43657274696669636174696f6e205365727669636573204469766973696f6e31383036060355040b132f2863292032303036207468617774652c20496e632e202d20466f7220617574686f72697a656420757365206f6e6c79311f301d06035504031316746861777465205072696d61727920526f6f7420434130820122300d06092a864886f70d01010105000382010f003082010a0282010100aca0f0fb8059d49cc7a4cf9da159730910450c0d2c6e68f16c5b4868495937fc0b3319c2777fcc102d95341ce6eb4d09a71cd2b8c9973602b789d4245f06c0cc4494948d02626feb5add118d289a5c8490107a0dbd74662f6a38a0e2d55444eb1d EAP-Message = 0x079f07ba6feee9fd4e0b29f53e84a001f19cabf81c7e89a4e8a1d871650da3517beebcd222600db95b9ddfbafc515b0baf98b2e92ee904e86287de2bc8d74ec14c641eddcf8758ba4a4fca68071d1c9d4ac6d52f91cc7c71721cc5c067eb32fdc9925c94da85c09bbf537d2b09f48c9d911f976a52cbde0936a477d87b875044d53e6e2969fb3949261e09a5807b402debe82785c9fe61fd7ee67c971dd59d0203010001a3423040300f0603551d130101ff040530030101ff300e0603551d0f0101ff040403020106301d0603551d0e041604147b5b45cfafcecb7afd31921a6ab6f346eb574850300d06092a864886f70d0101050500038201010079 EAP-Message = 0x11c04bb391b6fcf0 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x75706a9e767573896627c624035ec732 Finished request 3. Going to the next request Waking up in 4.6 seconds. rad_recv: Access-Request packet from host 10.32.33.1 port 32769, id=154, length=198 User-Name = "nicholas_kartsioukas" Calling-Station-Id = "00-23-4e-ba-6b-f4" Called-Station-Id = "00-1a-a2-c1-2c-30:test" NAS-Port = 29 NAS-IP-Address = 10.32.33.1 NAS-Identifier = "slo-wlc-1" Airespace-Wlan-Id = 5 Service-Type = Framed-User Framed-MTU = 1300 NAS-Port-Type = Wireless-802.11 Tunnel-Type:0 = VLAN Tunnel-Medium-Type:0 = IEEE-802 Tunnel-Private-Group-Id:0 = "17" EAP-Message = 0x020500061900 State = 0x75706a9e767573896627c624035ec732 Message-Authenticator = 0x4d63d0329ce97ccad52af8e0de982eeb # Executing section authorize from file /etc/freeradius/sites-enabled/default +- entering group authorize {...} ++[preprocess] returns ok [auth_log] expand: /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/freeradius/radacct/10.32.33.1/auth-detail-20110714 [auth_log] /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/10.32.33.1/auth-detail-20110714 [auth_log] expand: %t -> Thu Jul 14 16:45:39 2011 ++[auth_log] returns ok ++- entering policy rewrite_called_station_id {...} +++? if (Called-Station-Id =~ /^([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:]?([-a-z0-9_.]*)?/i) ? Evaluating (Called-Station-Id =~ /^([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:]?([-a-z0-9_.]*)?/i) -> TRUE +++? if (Called-Station-Id =~ /^([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:]?([-a-z0-9_.]*)?/i) -> TRUE +++- entering if (Called-Station-Id =~ /^([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:]?([-a-z0-9_.]*)?/i) {...} expand: %{1}%{2}%{3}%{4}%{5}%{6} -> 001aa2c12c30 expand: %{7} -> test ++++[request] returns ok +++- if (Called-Station-Id =~ /^([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:]?([-a-z0-9_.]*)?/i) returns ok +++ ... skipping else for request 4: Preceding "if" was taken ++- policy rewrite_called_station_id returns ok ++- entering switch Called-Station-Ssid {...} +++- entering case test {...} ++++- entering redundant-load-balance group redundant-load-balance {...} [ldap_prawn] performing user authorization for nicholas_kartsioukas [ldap_prawn] expand: %{Stripped-User-Name} -> [ldap_prawn] ... expanding second conditional [ldap_prawn] expand: %{User-Name} -> nicholas_kartsioukas [ldap_prawn] expand: (sAMAccountName=%{%{Stripped-User-Name}:-%{User-Name}}) -> (sAMAccountName=nicholas_kartsioukas) [ldap_prawn] expand: ou=CUESTA,dc=cuesta,dc=org -> ou=CUESTA,dc=cuesta,dc=org [ldap_prawn] ldap_get_conn: Checking Id: 0 [ldap_prawn] ldap_get_conn: Got Id: 0 [ldap_prawn] performing search in ou=CUESTA,dc=cuesta,dc=org, with filter (sAMAccountName=nicholas_kartsioukas) [ldap_prawn] No default NMAS login sequence [ldap_prawn] looking for check items in directory... [ldap_prawn] looking for reply items in directory... WARNING: No "known good" password was found in LDAP. Are you sure that the user is configured correctly? [ldap_prawn] user nicholas_kartsioukas authorized to use remote access [ldap_prawn] ldap_release_conn: Release Id: 0 +++++[ldap_prawn] returns ok ++++- redundant-load-balance group redundant-load-balance returns ok ++++[control] returns ok +++- case test returns ok ++- switch Called-Station-Ssid returns ok ++[files] returns noop ++[expiration] returns noop ++[logintime] returns noop Found Auth-Type = CUESTA # Executing group from file /etc/freeradius/sites-enabled/default +- entering group CUESTA {...} [eap_cuesta] Request found, released from the list [eap_cuesta] EAP/peap [eap_cuesta] processing type peap [peap] processing EAP-TLS [peap] Received TLS ACK [peap] ACK handshake fragment handler [peap] eaptls_verify returned 1 [peap] eaptls_process returned 13 [peap] EAPTLS_HANDLED ++[eap_cuesta] returns handled Sending Access-Challenge of id 154 to 10.32.33.1 port 32769 EAP-Message = 0x010603181900e967d40d6e45be55e893d2ce033fedda25b01d57cb1e3a76a04cec5076e864720ca4a9f1b88bd6d68784bb32e54111c077d9b3609deb1bd5d16e4444a9a601ec55621d77b85c8e48497c9c3b5711acad73378e2f785c906847d96060e6fc073d222017c4f716e9c4d872f9c8737cdf162f15a93efd6a27b6a1eb5aba981fd5e34d640a9d13c861baf5391c87bab8bd7b227ff6feac4079e5ac106f3d8f1b79768bc437b3211884e53600eb632099b9e9fe3304bb41c8c102f94463209e81ce42d3d63f2c76d3639c59dd8fa6e10ea02e41f72e9547cfbcfd33f3f60b617e7e912b8147c22730eea7105d378f5c392be404f07b8d568c68 EAP-Message = 0x160301020d0c0002090080a9ee3b7f4679d9a63fc5c7ae4dbfcc3388f359e11e7598ae7784d0ef1f39c9598b3eff3f3249f7be4198cf531149687b04183a2d01159f84572866d9d1e2ec0bf2b3799d9df5be606f42f8d39afbb16e6fc3848ca68b31bb76574697c42b752ba909a223db09a7cccd97105a1de3ba2a240e137549a9a6db21ef457a60e8d6e3000102008009f2e6265a233b6fc7a38860f4c38952fd402d02c462b662ee306e22ad5436e68bff4b7a60bb86759bd32de8947f9d82da6e3e215c18b87be01c4db8d660507c8792ba139ed379252f48a0994e3b6986a1e3d8fdb59321cfd5eed1dd6856c06de42934b90c8125f6be8d6fb746 EAP-Message = 0x3c139817f2bd0046a5c7580a1e54263855be260100555d69d4764c87519e531251e1545ee225756d1901e5454d75d061860ebf5fb81422d1f104dbec48e6bb0cc2149a4d77d428a202a509bc14c525ab8e95efb735c88693a6d29dc7c57b9e268d321a2aaeae25e338b177d21a324701b2d42be3ad65ffa6b54522dbadf9933d9ec0c8b22b79005d1427deec3ded9d98238b097d429e8f427c572edfdd7f5e1401e53d6b58beaf7b3c2b3f9212ca55fdf56f88ab96b112c823d7014f20958c9cd41b04477e16e30d0c0ee3da257cf6457079f9eea6005c0e3aa1d697e3f069d6198b99a9473f3a4dd249276e7af7ab9eef318f7f22ddfb14917af4633d EAP-Message = 0x6cad43341c993fcaec65d93c20522ad6e7f1b40395f7fea916030100040e000000 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x75706a9e717673896627c624035ec732 Finished request 4. Going to the next request Waking up in 4.6 seconds. rad_recv: Access-Request packet from host 10.32.33.1 port 32769, id=155, length=400 User-Name = "nicholas_kartsioukas" Calling-Station-Id = "00-23-4e-ba-6b-f4" Called-Station-Id = "00-1a-a2-c1-2c-30:test" NAS-Port = 29 NAS-IP-Address = 10.32.33.1 NAS-Identifier = "slo-wlc-1" Airespace-Wlan-Id = 5 Service-Type = Framed-User Framed-MTU = 1300 NAS-Port-Type = Wireless-802.11 Tunnel-Type:0 = VLAN Tunnel-Medium-Type:0 = IEEE-802 Tunnel-Private-Group-Id:0 = "17" EAP-Message = 0x020600d01980000000c616030100861000008200809b80196f3dc367bf8e33509c9196d0693796ecc0664aca987de2739ca5ba4770d1948949f120cdc2f690455aa35eae14272daa534ee2efbfdb9baf30cde59a94811b559f2b85339f9b68d5f00b3c159e0070265c8fc6b28e226ec9c91e3296feb04bf358e7d023d6b170d2024e8814a10003d02acdd3d63de4b7353f56918c6f14030100010116030100309e02598d0aa41ade41f8b70ae36cfafc80d4191f602a85c9d200738a507c5cef75c6c5670b6091b586c248e90ff0201a State = 0x75706a9e717673896627c624035ec732 Message-Authenticator = 0xad47af0b6301dc592b033ed480631991 # Executing section authorize from file /etc/freeradius/sites-enabled/default +- entering group authorize {...} ++[preprocess] returns ok [auth_log] expand: /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/freeradius/radacct/10.32.33.1/auth-detail-20110714 [auth_log] /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/10.32.33.1/auth-detail-20110714 [auth_log] expand: %t -> Thu Jul 14 16:45:40 2011 ++[auth_log] returns ok ++- entering policy rewrite_called_station_id {...} +++? if (Called-Station-Id =~ /^([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:]?([-a-z0-9_.]*)?/i) ? Evaluating (Called-Station-Id =~ /^([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:]?([-a-z0-9_.]*)?/i) -> TRUE +++? if (Called-Station-Id =~ /^([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:]?([-a-z0-9_.]*)?/i) -> TRUE +++- entering if (Called-Station-Id =~ /^([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:]?([-a-z0-9_.]*)?/i) {...} expand: %{1}%{2}%{3}%{4}%{5}%{6} -> 001aa2c12c30 expand: %{7} -> test ++++[request] returns ok +++- if (Called-Station-Id =~ /^([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:]?([-a-z0-9_.]*)?/i) returns ok +++ ... skipping else for request 5: Preceding "if" was taken ++- policy rewrite_called_station_id returns ok ++- entering switch Called-Station-Ssid {...} +++- entering case test {...} ++++- entering redundant-load-balance group redundant-load-balance {...} [ldap_prawn] performing user authorization for nicholas_kartsioukas [ldap_prawn] expand: %{Stripped-User-Name} -> [ldap_prawn] ... expanding second conditional [ldap_prawn] expand: %{User-Name} -> nicholas_kartsioukas [ldap_prawn] expand: (sAMAccountName=%{%{Stripped-User-Name}:-%{User-Name}}) -> (sAMAccountName=nicholas_kartsioukas) [ldap_prawn] expand: ou=CUESTA,dc=cuesta,dc=org -> ou=CUESTA,dc=cuesta,dc=org [ldap_prawn] ldap_get_conn: Checking Id: 0 [ldap_prawn] ldap_get_conn: Got Id: 0 [ldap_prawn] performing search in ou=CUESTA,dc=cuesta,dc=org, with filter (sAMAccountName=nicholas_kartsioukas) [ldap_prawn] No default NMAS login sequence [ldap_prawn] looking for check items in directory... [ldap_prawn] looking for reply items in directory... WARNING: No "known good" password was found in LDAP. Are you sure that the user is configured correctly? [ldap_prawn] user nicholas_kartsioukas authorized to use remote access [ldap_prawn] ldap_release_conn: Release Id: 0 +++++[ldap_prawn] returns ok ++++- redundant-load-balance group redundant-load-balance returns ok ++++[control] returns ok +++- case test returns ok ++- switch Called-Station-Ssid returns ok ++[files] returns noop ++[expiration] returns noop ++[logintime] returns noop Found Auth-Type = CUESTA # Executing group from file /etc/freeradius/sites-enabled/default +- entering group CUESTA {...} [eap_cuesta] Request found, released from the list [eap_cuesta] EAP/peap [eap_cuesta] processing type peap [peap] processing EAP-TLS TLS Length 198 [peap] Length Included [peap] eaptls_verify returned 11 [peap] <<< TLS 1.0 Handshake [length 0086], ClientKeyExchange [peap] TLS_accept: SSLv3 read client key exchange A [peap] <<< TLS 1.0 ChangeCipherSpec [length 0001] [peap] <<< TLS 1.0 Handshake [length 0010], Finished [peap] TLS_accept: SSLv3 read finished A [peap] >>> TLS 1.0 ChangeCipherSpec [length 0001] [peap] TLS_accept: SSLv3 write change cipher spec A [peap] >>> TLS 1.0 Handshake [length 0010], Finished [peap] TLS_accept: SSLv3 write finished A [peap] TLS_accept: SSLv3 flush data [peap] (other): SSL negotiation finished successfully SSL Connection Established [peap] eaptls_process returned 13 [peap] EAPTLS_HANDLED ++[eap_cuesta] returns handled Sending Access-Challenge of id 155 to 10.32.33.1 port 32769 EAP-Message = 0x0107004119001403010001011603010030dabbc17c6b0cfab40d8f61a6eb87d1fd7e167ef50abbebc8d78845fe0fc140cef93c906fc1a205f3986f526df228731e Message-Authenticator = 0x00000000000000000000000000000000 State = 0x75706a9e707773896627c624035ec732 Finished request 5. Going to the next request Waking up in 4.3 seconds. rad_recv: Access-Request packet from host 10.32.33.1 port 32769, id=156, length=198 User-Name = "nicholas_kartsioukas" Calling-Station-Id = "00-23-4e-ba-6b-f4" Called-Station-Id = "00-1a-a2-c1-2c-30:test" NAS-Port = 29 NAS-IP-Address = 10.32.33.1 NAS-Identifier = "slo-wlc-1" Airespace-Wlan-Id = 5 Service-Type = Framed-User Framed-MTU = 1300 NAS-Port-Type = Wireless-802.11 Tunnel-Type:0 = VLAN Tunnel-Medium-Type:0 = IEEE-802 Tunnel-Private-Group-Id:0 = "17" EAP-Message = 0x020700061900 State = 0x75706a9e707773896627c624035ec732 Message-Authenticator = 0x8b684625116611269639280fa269375c # Executing section authorize from file /etc/freeradius/sites-enabled/default +- entering group authorize {...} ++[preprocess] returns ok [auth_log] expand: /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/freeradius/radacct/10.32.33.1/auth-detail-20110714 [auth_log] /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/10.32.33.1/auth-detail-20110714 [auth_log] expand: %t -> Thu Jul 14 16:45:40 2011 ++[auth_log] returns ok ++- entering policy rewrite_called_station_id {...} +++? if (Called-Station-Id =~ /^([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:]?([-a-z0-9_.]*)?/i) ? Evaluating (Called-Station-Id =~ /^([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:]?([-a-z0-9_.]*)?/i) -> TRUE +++? if (Called-Station-Id =~ /^([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:]?([-a-z0-9_.]*)?/i) -> TRUE +++- entering if (Called-Station-Id =~ /^([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:]?([-a-z0-9_.]*)?/i) {...} expand: %{1}%{2}%{3}%{4}%{5}%{6} -> 001aa2c12c30 expand: %{7} -> test ++++[request] returns ok +++- if (Called-Station-Id =~ /^([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:]?([-a-z0-9_.]*)?/i) returns ok +++ ... skipping else for request 6: Preceding "if" was taken ++- policy rewrite_called_station_id returns ok ++- entering switch Called-Station-Ssid {...} +++- entering case test {...} ++++- entering redundant-load-balance group redundant-load-balance {...} [ldap_pike] performing user authorization for nicholas_kartsioukas [ldap_pike] expand: %{Stripped-User-Name} -> [ldap_pike] ... expanding second conditional [ldap_pike] expand: %{User-Name} -> nicholas_kartsioukas [ldap_pike] expand: (sAMAccountName=%{%{Stripped-User-Name}:-%{User-Name}}) -> (sAMAccountName=nicholas_kartsioukas) [ldap_pike] expand: ou=CUESTA,dc=cuesta,dc=org -> ou=CUESTA,dc=cuesta,dc=org [ldap_pike] ldap_get_conn: Checking Id: 0 [ldap_pike] ldap_get_conn: Got Id: 0 [ldap_pike] attempting LDAP reconnection [ldap_pike] (re)connect to pike.cuesta.org:389, authentication 0 [ldap_pike] starting TLS [ldap_pike] bind as freeradius@cuesta.org/* to pike.cuesta.org:389 [ldap_pike] waiting for bind result ... [ldap_pike] Bind was successful [ldap_pike] performing search in ou=CUESTA,dc=cuesta,dc=org, with filter (sAMAccountName=nicholas_kartsioukas) [ldap_pike] No default NMAS login sequence [ldap_pike] looking for check items in directory... [ldap_pike] looking for reply items in directory... WARNING: No "known good" password was found in LDAP. Are you sure that the user is configured correctly? [ldap_pike] user nicholas_kartsioukas authorized to use remote access [ldap_pike] ldap_release_conn: Release Id: 0 +++++[ldap_pike] returns ok ++++- redundant-load-balance group redundant-load-balance returns ok ++++[control] returns ok +++- case test returns ok ++- switch Called-Station-Ssid returns ok ++[files] returns noop ++[expiration] returns noop ++[logintime] returns noop Found Auth-Type = CUESTA # Executing group from file /etc/freeradius/sites-enabled/default +- entering group CUESTA {...} [eap_cuesta] Request found, released from the list [eap_cuesta] EAP/peap [eap_cuesta] processing type peap [peap] processing EAP-TLS [peap] Received TLS ACK [peap] ACK handshake is finished [peap] eaptls_verify returned 3 [peap] eaptls_process returned 3 [peap] EAPTLS_SUCCESS [peap] Session established. Decoding tunneled attributes. [peap] Peap state TUNNEL ESTABLISHED ++[eap_cuesta] returns handled Sending Access-Challenge of id 156 to 10.32.33.1 port 32769 EAP-Message = 0x0108002b19001703010020ca277c81f31b90dbb7d16e19352d8b07da8b2dd1a3c6003c2ac934d78792ef55 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x75706a9e737873896627c624035ec732 Finished request 6. Going to the next request Waking up in 4.3 seconds. rad_recv: Access-Request packet from host 10.32.33.1 port 32769, id=157, length=288 User-Name = "nicholas_kartsioukas" Calling-Station-Id = "00-23-4e-ba-6b-f4" Called-Station-Id = "00-1a-a2-c1-2c-30:test" NAS-Port = 29 NAS-IP-Address = 10.32.33.1 NAS-Identifier = "slo-wlc-1" Airespace-Wlan-Id = 5 Service-Type = Framed-User Framed-MTU = 1300 NAS-Port-Type = Wireless-802.11 Tunnel-Type:0 = VLAN Tunnel-Medium-Type:0 = IEEE-802 Tunnel-Private-Group-Id:0 = "17" EAP-Message = 0x0208006019001703010020415368b51ddb31163565c52cd4ec10b48947d89d02e0923cf9e8ab3e9dc0b1b317030100307036a2fe5771d6c79fc6ec75d7ce6af4fe757eef03669368bc6bc3e92eb60c556718118d9053ccf71665053d99423dac State = 0x75706a9e737873896627c624035ec732 Message-Authenticator = 0x1cd132c92ffcfcaf3329d2e1be8559b4 # Executing section authorize from file /etc/freeradius/sites-enabled/default +- entering group authorize {...} ++[preprocess] returns ok [auth_log] expand: /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/freeradius/radacct/10.32.33.1/auth-detail-20110714 [auth_log] /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/10.32.33.1/auth-detail-20110714 [auth_log] expand: %t -> Thu Jul 14 16:45:40 2011 ++[auth_log] returns ok ++- entering policy rewrite_called_station_id {...} +++? if (Called-Station-Id =~ /^([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:]?([-a-z0-9_.]*)?/i) ? Evaluating (Called-Station-Id =~ /^([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:]?([-a-z0-9_.]*)?/i) -> TRUE +++? if (Called-Station-Id =~ /^([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:]?([-a-z0-9_.]*)?/i) -> TRUE +++- entering if (Called-Station-Id =~ /^([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:]?([-a-z0-9_.]*)?/i) {...} expand: %{1}%{2}%{3}%{4}%{5}%{6} -> 001aa2c12c30 expand: %{7} -> test ++++[request] returns ok +++- if (Called-Station-Id =~ /^([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:]?([-a-z0-9_.]*)?/i) returns ok +++ ... skipping else for request 7: Preceding "if" was taken ++- policy rewrite_called_station_id returns ok ++- entering switch Called-Station-Ssid {...} +++- entering case test {...} ++++- entering redundant-load-balance group redundant-load-balance {...} [ldap_parrotfish] performing user authorization for nicholas_kartsioukas [ldap_parrotfish] expand: %{Stripped-User-Name} -> [ldap_parrotfish] ... expanding second conditional [ldap_parrotfish] expand: %{User-Name} -> nicholas_kartsioukas [ldap_parrotfish] expand: (sAMAccountName=%{%{Stripped-User-Name}:-%{User-Name}}) -> (sAMAccountName=nicholas_kartsioukas) [ldap_parrotfish] expand: ou=CUESTA,dc=cuesta,dc=org -> ou=CUESTA,dc=cuesta,dc=org [ldap_parrotfish] ldap_get_conn: Checking Id: 0 [ldap_parrotfish] ldap_get_conn: Got Id: 0 [ldap_parrotfish] performing search in ou=CUESTA,dc=cuesta,dc=org, with filter (sAMAccountName=nicholas_kartsioukas) [ldap_parrotfish] No default NMAS login sequence [ldap_parrotfish] looking for check items in directory... [ldap_parrotfish] looking for reply items in directory... WARNING: No "known good" password was found in LDAP. Are you sure that the user is configured correctly? [ldap_parrotfish] user nicholas_kartsioukas authorized to use remote access [ldap_parrotfish] ldap_release_conn: Release Id: 0 +++++[ldap_parrotfish] returns ok ++++- redundant-load-balance group redundant-load-balance returns ok ++++[control] returns ok +++- case test returns ok ++- switch Called-Station-Ssid returns ok ++[files] returns noop ++[expiration] returns noop ++[logintime] returns noop Found Auth-Type = CUESTA # Executing group from file /etc/freeradius/sites-enabled/default +- entering group CUESTA {...} [eap_cuesta] Request found, released from the list [eap_cuesta] EAP/peap [eap_cuesta] processing type peap [peap] processing EAP-TLS [peap] eaptls_verify returned 7 [peap] Done initial handshake [peap] eaptls_process returned 7 [peap] EAPTLS_OK [peap] Session established. Decoding tunneled attributes. [peap] Peap state WAITING FOR INNER IDENTITY [peap] Identity - nicholas_kartsioukas [peap] Got inner identity 'nicholas_kartsioukas' [peap] Setting default EAP type for tunneled EAP session. [peap] Got tunneled request EAP-Message = 0x02080019016e6963686f6c61735f6b61727473696f756b6173 server { PEAP: Setting User-Name to nicholas_kartsioukas Sending tunneled request EAP-Message = 0x02080019016e6963686f6c61735f6b61727473696f756b6173 FreeRADIUS-Proxied-To = 127.0.0.1 User-Name = "nicholas_kartsioukas" server { # Executing section authorize from file /etc/freeradius/sites-enabled/default +- entering group authorize {...} ++[preprocess] returns ok [auth_log] expand: /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/freeradius/radacct/10.32.33.1/auth-detail-20110714 [auth_log] /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/10.32.33.1/auth-detail-20110714 [auth_log] expand: %t -> Thu Jul 14 16:45:40 2011 ++[auth_log] returns ok ++- entering policy rewrite_called_station_id {...} +++? if (Called-Station-Id =~ /^([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:]?([-a-z0-9_.]*)?/i) (Attribute Called-Station-Id was not found) ? Evaluating (Called-Station-Id =~ /^([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:]?([-a-z0-9_.]*)?/i) -> FALSE +++? if (Called-Station-Id =~ /^([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:]?([-a-z0-9_.]*)?/i) -> FALSE +++- entering else else {...} ++++[noop] returns noop +++- else else returns noop ++- policy rewrite_called_station_id returns noop ++- entering switch Called-Station-Ssid {...} +++- switch Called-Station-Ssid returns notfound ++- group authorize returns notfound ++[files] returns noop ++[expiration] returns noop ++[logintime] returns noop ERROR: No authenticate method (Auth-Type) found for the request: Rejecting the user Failed to authenticate the user. Login incorrect: [nicholas_kartsioukas] (from client slo-wlc1 port 0 via TLS tunnel) } # server [peap] Got tunneled reply code 3 [peap] Got tunneled reply RADIUS code 3 [peap] Tunneled authentication was rejected. [peap] FAILURE ++[eap_cuesta] returns handled Sending Access-Challenge of id 157 to 10.32.33.1 port 32769 EAP-Message = 0x0109003b19001703010030bd7b71200ce74202d6b1bd96d4e76d6ba7ee554bbc6ea0440594be820d87b179d5a4fa88831fd9025a2097ff7e038e28 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x75706a9e727973896627c624035ec732 Finished request 7. Going to the next request Waking up in 4.3 seconds. rad_recv: Access-Request packet from host 10.32.33.1 port 32769, id=158, length=288 User-Name = "nicholas_kartsioukas" Calling-Station-Id = "00-23-4e-ba-6b-f4" Called-Station-Id = "00-1a-a2-c1-2c-30:test" NAS-Port = 29 NAS-IP-Address = 10.32.33.1 NAS-Identifier = "slo-wlc-1" Airespace-Wlan-Id = 5 Service-Type = Framed-User Framed-MTU = 1300 NAS-Port-Type = Wireless-802.11 Tunnel-Type:0 = VLAN Tunnel-Medium-Type:0 = IEEE-802 Tunnel-Private-Group-Id:0 = "17" EAP-Message = 0x0209006019001703010020f24e36254f893a9238aeeac05c4be6b0dc20da96a70acbeb802595cd1dff6ddc17030100304a667d0f1259572c885692c70e2ee3f1cd88a69e105ee87cc9e12ab9a34e6dd90d9886eacce9fc424d290e99d734ee4b State = 0x75706a9e727973896627c624035ec732 Message-Authenticator = 0x62adee6440c2347147c6231de0e4b95a # Executing section authorize from file /etc/freeradius/sites-enabled/default +- entering group authorize {...} ++[preprocess] returns ok [auth_log] expand: /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/freeradius/radacct/10.32.33.1/auth-detail-20110714 [auth_log] /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/10.32.33.1/auth-detail-20110714 [auth_log] expand: %t -> Thu Jul 14 16:45:40 2011 ++[auth_log] returns ok ++- entering policy rewrite_called_station_id {...} +++? if (Called-Station-Id =~ /^([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:]?([-a-z0-9_.]*)?/i) ? Evaluating (Called-Station-Id =~ /^([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:]?([-a-z0-9_.]*)?/i) -> TRUE +++? if (Called-Station-Id =~ /^([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:]?([-a-z0-9_.]*)?/i) -> TRUE +++- entering if (Called-Station-Id =~ /^([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:]?([-a-z0-9_.]*)?/i) {...} expand: %{1}%{2}%{3}%{4}%{5}%{6} -> 001aa2c12c30 expand: %{7} -> test ++++[request] returns ok +++- if (Called-Station-Id =~ /^([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:.]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:]?([-a-z0-9_.]*)?/i) returns ok +++ ... skipping else for request 8: Preceding "if" was taken ++- policy rewrite_called_station_id returns ok ++- entering switch Called-Station-Ssid {...} +++- entering case test {...} ++++- entering redundant-load-balance group redundant-load-balance {...} [ldap_parrotfish] performing user authorization for nicholas_kartsioukas [ldap_parrotfish] expand: %{Stripped-User-Name} -> [ldap_parrotfish] ... expanding second conditional [ldap_parrotfish] expand: %{User-Name} -> nicholas_kartsioukas [ldap_parrotfish] expand: (sAMAccountName=%{%{Stripped-User-Name}:-%{User-Name}}) -> (sAMAccountName=nicholas_kartsioukas) [ldap_parrotfish] expand: ou=CUESTA,dc=cuesta,dc=org -> ou=CUESTA,dc=cuesta,dc=org [ldap_parrotfish] ldap_get_conn: Checking Id: 0 [ldap_parrotfish] ldap_get_conn: Got Id: 0 [ldap_parrotfish] performing search in ou=CUESTA,dc=cuesta,dc=org, with filter (sAMAccountName=nicholas_kartsioukas) [ldap_parrotfish] No default NMAS login sequence [ldap_parrotfish] looking for check items in directory... [ldap_parrotfish] looking for reply items in directory... WARNING: No "known good" password was found in LDAP. Are you sure that the user is configured correctly? [ldap_parrotfish] user nicholas_kartsioukas authorized to use remote access [ldap_parrotfish] ldap_release_conn: Release Id: 0 +++++[ldap_parrotfish] returns ok ++++- redundant-load-balance group redundant-load-balance returns ok ++++[control] returns ok +++- case test returns ok ++- switch Called-Station-Ssid returns ok ++[files] returns noop ++[expiration] returns noop ++[logintime] returns noop Found Auth-Type = CUESTA # Executing group from file /etc/freeradius/sites-enabled/default +- entering group CUESTA {...} [eap_cuesta] Request found, released from the list [eap_cuesta] EAP/peap [eap_cuesta] processing type peap [peap] processing EAP-TLS [peap] eaptls_verify returned 7 [peap] Done initial handshake [peap] eaptls_process returned 7 [peap] EAPTLS_OK [peap] Session established. Decoding tunneled attributes. [peap] Peap state send tlv failure [peap] Received EAP-TLV response. [peap] The users session was previously rejected: returning reject (again.) [peap] *** This means you need to read the PREVIOUS messages in the debug output [peap] *** to find out the reason why the user was rejected. [peap] *** Look for "reject" or "fail". Those earlier messages will tell you. [peap] *** what went wrong, and how to fix the problem. [eap_cuesta] Handler failed in EAP/peap [eap_cuesta] Failed in EAP select ++[eap_cuesta] returns invalid Failed to authenticate the user. Login incorrect: [nicholas_kartsioukas] (from client slo-wlc1 port 29 cli 00-23-4e-ba-6b-f4) Using Post-Auth-Type Reject # Executing group from file /etc/freeradius/sites-enabled/default +- entering group REJECT {...} [attr_filter.access_reject] expand: %{User-Name} -> nicholas_kartsioukas attr_filter: Matched entry DEFAULT at line 11 ++[attr_filter.access_reject] returns updated Delaying reject of request 8 for 1 seconds Going to the next request Waking up in 0.9 seconds. Sending delayed reject for request 8 Sending Access-Reject of id 158 to 10.32.33.1 port 32769 EAP-Message = 0x04090004 Message-Authenticator = 0x00000000000000000000000000000000 Waking up in 3.2 seconds. Cleaning up request 0 ID 150 with timestamp +24 Waking up in 0.2 seconds. Cleaning up request 1 ID 151 with timestamp +29 Cleaning up request 2 ID 152 with timestamp +29 Cleaning up request 3 ID 153 with timestamp +29 Cleaning up request 4 ID 154 with timestamp +29 Waking up in 0.2 seconds. Cleaning up request 5 ID 155 with timestamp +30 Cleaning up request 6 ID 156 with timestamp +30 Cleaning up request 7 ID 157 with timestamp +30 Waking up in 1.0 seconds. Cleaning up request 8 ID 158 with timestamp +30 Ready to process requests.