session log in SQL

Khapare Joshi khapare77 at gmail.com
Wed Apr 8 12:22:33 CEST 2015


Thanks alan,

I did mistake on regex thing because I was also testing same with
affiliation and had this lines before I turn to test gid thing. sorry for
this
        if (affiliation =~ /^staff/) {
                  update control {
                   Simultaneous-Use := 2
               }
             }
        else {
                  update control {
                   Simultaneous-Use := 1
               }
            }

This did not work either.

My problem is :

If I add, in users file and remove those gid check in
/etc/radd/site-enabled/default authorize section, it works
DEFAULT Simultaneous-Use := 1
          Fall-Through = 1

But when I comment those line in users file and add the gid checking
statement in /etc/radd/site-enabled/default section it does not.
if (gidnumber < 200){
               update request {
               Simultaneous-Use := 1
               }
        }
         else{
               update request {
               Simultaneous-Use := 2
               }
        }

I checked both debug output, the first one (DEFAULT Simultaneous-Use :=
1          Fall-Through = 1)  actually executes session but i don't see
these lines when i perform test with gidnumber check statement.  I don't
know why session section is not executed when doing gidnumber check. is
there otherway to do this from users file ?


} # group authenticate = ok
# Executing section session from file /etc/raddb/sites-enabled/inner-tunnel
+group session {
[sql]     expand: %{Stripped-User-Name} -> testsim
[sql]     expand: %{%{Stripped-User-Name}:-%{%{User-Name}:-DEFAULT}} ->
testsim
[sql] sql_set_user escaped user --> 'testsim'
[sql]     expand: SELECT COUNT(*)                              FROM
radacct                              WHERE username =
'%{SQL-User-Name}'                              AND acctstoptime IS NULL ->
SELECT COUNT(*)                              FROM
radacct                              WHERE username =
'testsim'                              AND acctstoptime IS NULL
rlm_sql (sql): Reserving sql socket id: 31
rlm_sql (sql): Released sql socket id: 31
++[sql] = ok


Full debug log from enabling gidnumber checking. in debug output below,
user testsim has guid number less than 200 and he should be rejected the
second attempt
[root at radiusserver ~]# ./radwhosql
+----------+---------------+-----------+-----------------+---------------------+
| username | acctsessionid | nasportid | nasporttype     |
acctstarttime       |
+----------+---------------+-----------+-----------------+---------------------+
| testsim  | 00001D62      | 7538      | Wireless-802.11 | 2015-04-08
09:11:33 |
| testsim  | 00001D63      | 7539      | Wireless-802.11 | 2015-04-08
09:12:45 |
+----------+---------------+-----------+-----------------+---------------------+

 ... adding new socket proxy address * port 36092
 ... adding new socket proxy address * port 41887
Listening on authentication address * port 1812
Listening on accounting address * port 1813
Listening on command file /var/run/radiusd/radiusd.sock
Listening on authentication address 127.0.0.1 port 18120 as server
inner-tunnel
Listening on proxy address * port 1814
Ready to process requests.
rad_recv: Access-Request packet from host 10.128.5.1 port 1645, id=105,
length=143
    User-Name = "testsim"
    Framed-MTU = 1400
    Called-Station-Id = "001d.a282.dda0"
    Calling-Station-Id = "0021.5c5b.8ef3"
    Service-Type = Login-User
    Message-Authenticator = 0x809bb623f79781b2743705c61882eaea
    EAP-Message = 0x02020012016e656d616e64694068692e6973
    NAS-Port-Type = Wireless-802.11
    NAS-Port = 7538
    NAS-IP-Address = 10.128.5.1
    NAS-Identifier = "nas1"
# Executing section authorize from file /etc/raddb/sites-enabled/default
+group authorize {
++? if (!(User-Name =~
/^([^@]*)@(([-A-Z0-9]+\.)*[-A-Z0-9]+(\\.[-A-Z0-9]+)+)$/i))
?? Evaluating (User-Name =~
/^([^@]*)@(([-A-Z0-9]+\.)*[-A-Z0-9]+(\\.[-A-Z0-9]+)+)$/i) -> TRUE
? Converting !TRUE -> FALSE
++? if (!(User-Name =~
/^([^@]*)@(([-A-Z0-9]+\.)*[-A-Z0-9]+(\\.[-A-Z0-9]+)+)$/i)) -> FALSE
++else else {
+++update request {
    expand: %{1} -> testsim
    expand: %{2} -> example.com
+++} # update request = noop
+++? if (Realm == "example.com")
? Evaluating (Realm == "example.com") -> TRUE
+++? if (Realm == "example.com") -> TRUE
+++if (Realm == "example.com") {
++++update control {
++++} # update control = noop
+++} # if (Realm == "example.com") = noop
+++ ... skipping else for request 0: Preceding "if" was taken
++} # else else = noop
++[preprocess] = ok
[auth_log]     expand: %{Packet-Src-IP-Address} -> 10.128.5.1
[auth_log]     expand:
/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d
-> /var/log/radius/radacct/10.128.5.1/auth-detail-20150408
[auth_log]
/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d
expands to /var/log/radius/radacct/10.128.5.1/auth-detail-20150408
[auth_log]     expand: %t -> Wed Apr  8 09:11:33 2015
++[auth_log] = ok
++[mschap] = noop
[eap] EAP packet type response id 2 length 18
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] = updated
++[files] = noop
[ldap] performing user authorization for testsim
[ldap]     expand: %{Stripped-User-Name} -> testsim
[ldap]     expand: (uid=%{%{Stripped-User-Name}:-%{User-Name}}) ->
(uid=testsim)
[ldap]     expand: dc=example,dc=com -> dc=example,dc=com
  [ldap] ldap_get_conn: Checking Id: 0
  [ldap] ldap_get_conn: Got Id: 0
  [ldap] attempting LDAP reconnection
  [ldap] (re)connect to ldap.example.com:389, authentication 0
  [ldap] bind as cn=radius,ou=RT,dc=example,dc=com/radiuspass to
ldap.example.com:389
  [ldap] waiting for bind result ...
  [ldap] Bind was successful
  [ldap] performing search in dc=example,dc=com, with filter (uid=testsim)
[ldap] looking for check items in directory...
  [ldap] gidnumber -> gidnumber == 151
[ldap] 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] ldap_release_conn: Release Id: 0
++[ldap] = ok
++? if (notfound)
? Evaluating (notfound) -> FALSE
++? if (notfound) -> FALSE
++? if (gidnumber < 200)
    (Attribute gidnumber was not found)
? Evaluating (gidnumber < 200) -> FALSE
++? if (gidnumber < 200) -> FALSE
++else else {
+++update request {
+++} # update request = noop
++} # else else = noop
++[expiration] = noop
++[logintime] = noop
++[pap] = noop
+} # group authorize = updated
Found Auth-Type = EAP
# Executing group from file /etc/raddb/sites-enabled/default
+group authenticate {
[eap] EAP Identity
[eap] processing type tls
[tls] Initiate
[tls] Start returned 1
++[eap] = handled
+} # group authenticate = handled
Sending Access-Challenge of id 105 to 10.128.5.1 port 1645
    EAP-Message = 0x010300061920
    Message-Authenticator = 0x00000000000000000000000000000000
    State = 0x38b5088238b6118958da8558fbdf02b8
Finished request 0.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.128.5.1 port 1645, id=106,
length=250
    User-Name = "testsim"
    Framed-MTU = 1400
    Called-Station-Id = "001d.a282.dda0"
    Calling-Station-Id = "0021.5c5b.8ef3"
    Service-Type = Login-User
    Message-Authenticator = 0x185aaf022bec98d76bd695425cc3d049
    EAP-Message =
0x0203006b198000000061160301005c0100005803015524f0c79d36fe5ef15e2fdf4bc55c87462bb4819f6e4c7996013507046c4587000018c014c013c00ac0090035002f00380032000a00130005000401000017000a00080006001900170018000b00020100ff01000100

    NAS-Port-Type = Wireless-802.11
    NAS-Port = 7538
    State = 0x38b5088238b6118958da8558fbdf02b8
    NAS-IP-Address = 10.128.5.1
    NAS-Identifier = "nas1"
# Executing section authorize from file /etc/raddb/sites-enabled/default
+group authorize {
++? if (!(User-Name =~
/^([^@]*)@(([-A-Z0-9]+\.)*[-A-Z0-9]+(\\.[-A-Z0-9]+)+)$/i))
?? Evaluating (User-Name =~
/^([^@]*)@(([-A-Z0-9]+\.)*[-A-Z0-9]+(\\.[-A-Z0-9]+)+)$/i) -> TRUE
? Converting !TRUE -> FALSE
++? if (!(User-Name =~
/^([^@]*)@(([-A-Z0-9]+\.)*[-A-Z0-9]+(\\.[-A-Z0-9]+)+)$/i)) -> FALSE
++else else {
+++update request {
    expand: %{1} -> testsim
    expand: %{2} -> example.com
+++} # update request = noop
+++? if (Realm == "example.com")
? Evaluating (Realm == "example.com") -> TRUE
+++? if (Realm == "example.com") -> TRUE
+++if (Realm == "example.com") {
++++update control {
++++} # update control = noop
+++} # if (Realm == "example.com") = noop
+++ ... skipping else for request 1: Preceding "if" was taken
++} # else else = noop
++[preprocess] = ok
[auth_log]     expand: %{Packet-Src-IP-Address} -> 10.128.5.1
[auth_log]     expand:
/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d
-> /var/log/radius/radacct/10.128.5.1/auth-detail-20150408
[auth_log]
/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d
expands to /var/log/radius/radacct/10.128.5.1/auth-detail-20150408
[auth_log]     expand: %t -> Wed Apr  8 09:11:33 2015
++[auth_log] = ok
++[mschap] = noop
[eap] EAP packet type response id 3 length 107
[eap] Continuing tunnel setup.
++[eap] = ok
+} # group authorize = ok
Found Auth-Type = EAP
# Executing group from file /etc/raddb/sites-enabled/default
+group authenticate {
[eap] Request found, released from the list
[eap] EAP/peap
[eap] processing type peap
[peap] processing EAP-TLS
  TLS Length 97
[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 005c], 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 085e], Certificate
[peap]     TLS_accept: SSLv3 write certificate 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] = handled
+} # group authenticate = handled
Sending Access-Challenge of id 106 to 10.128.5.1 port 1645
    EAP-Message =
0x0104040019c0000008a216030100310200002d03015524f0c502a93602ded979bafcbae841e9054d84246fc2e44f22e3ea5986474b000035000005ff01000100160301085e0b00085a0008570003a6308203a23082028aa003020102020101300d06092a864886f70d0101050500308193310b3009060355040613024652310f300d060355040813065261646975733112301006035504071309536f6d65776865726531153013060355040a130c4578616d706c6520496e632e3120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d312630240603550403131d4578616d706c65204365727469666963617465204175

    EAP-Message =
0x74686f72697479301e170d3134313130353231353435345a170d3135303130343231353435345a307c310b3009060355040613024652310f300d0603550408130652616469757331153013060355040a130c4578616d706c6520496e632e312330210603550403131a4578616d706c65205365727665722043657274696669636174653120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d30820122300d06092a864886f70d01010105000382010f003082010a0282010100d257278bcb3d80351c6c39a144f9ee55accaf13aa2bdc5e78c1191b6126542cdb0b8edf81f72bc80e905d30fe95d9f54200778bff7e808

    EAP-Message =
0xd3008941f8b7da00b5d9cf77bed1c1d2accd8f2aac95f6c4c549a0e64d0fffb372ee90b5e1752c7450c1fc302fcd9122cbb63e3d2f8400a5a2071690238d5133b80e96eaac6fa15e185dd390c51255309adac0be363f5e626ae745f05eeed35f3997c05377c2291ea6df65a6d6cc56ab9880776317cc9894557344f92eb982673e07ed5c027687eb46d2167c0cd7756404587c37319482497afd9bffe114ef64a2b0640add64df47d92e37f32d94720451964ce39276ae8fb94fdf2f3fba10b51ab2e84fb2804986a30203010001a317301530130603551d25040c300a06082b06010505070301300d06092a864886f70d01010505000382010100359a

    EAP-Message =
0xd6555994880868e54137c4d487acaeccded09ea5d265a1b2faa142dc0e8214b112cea1077f91d8e77a0516ad66524e964fc108774fa3538f4d8de1cbd41a08d4f356ccebb3a1fabcfd2b40d3ab12ff487995b42176e9201c165c4e00ac79be6379578bfa1109299015652b9c9160abff3ab2b87027590f6f46bd817cac00b168a06203959212727cec0bcb8555ff7c47e05bf459bee769989ba4c15619ab4256ed025b5c93e2f4316ad86167b1186e71aa407ad5e3e283ab0d3637b189f0ab5a0c9cbf73446230f511cc2b60da090f6c46842b61437c8e841f44b32d01b6d4e676cb23c7b5c9bfd20e6df238342e7de3596789f62dd5b3fd77f76654b2

    EAP-Message = 0x3f0004ab308204a73082038f
    Message-Authenticator = 0x00000000000000000000000000000000
    State = 0x38b5088239b1118958da8558fbdf02b8
Finished request 1.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.128.5.1 port 1645, id=107,
length=149
    User-Name = "testsim"
    Framed-MTU = 1400
    Called-Station-Id = "001d.a282.dda0"
    Calling-Station-Id = "0021.5c5b.8ef3"
    Service-Type = Login-User
    Message-Authenticator = 0x357bfabbbad97573632a2cb4094fceef
    EAP-Message = 0x020400061900
    NAS-Port-Type = Wireless-802.11
    NAS-Port = 7538
    State = 0x38b5088239b1118958da8558fbdf02b8
    NAS-IP-Address = 10.128.5.1
    NAS-Identifier = "nas1"
# Executing section authorize from file /etc/raddb/sites-enabled/default
+group authorize {
++? if (!(User-Name =~
/^([^@]*)@(([-A-Z0-9]+\.)*[-A-Z0-9]+(\\.[-A-Z0-9]+)+)$/i))
?? Evaluating (User-Name =~
/^([^@]*)@(([-A-Z0-9]+\.)*[-A-Z0-9]+(\\.[-A-Z0-9]+)+)$/i) -> TRUE
? Converting !TRUE -> FALSE
++? if (!(User-Name =~
/^([^@]*)@(([-A-Z0-9]+\.)*[-A-Z0-9]+(\\.[-A-Z0-9]+)+)$/i)) -> FALSE
++else else {
+++update request {
    expand: %{1} -> testsim
    expand: %{2} -> example.com
+++} # update request = noop
+++? if (Realm == "example.com")
? Evaluating (Realm == "example.com") -> TRUE
+++? if (Realm == "example.com") -> TRUE
+++if (Realm == "example.com") {
++++update control {
++++} # update control = noop
+++} # if (Realm == "example.com") = noop
+++ ... skipping else for request 2: Preceding "if" was taken
++} # else else = noop
++[preprocess] = ok
[auth_log]     expand: %{Packet-Src-IP-Address} -> 10.128.5.1
[auth_log]     expand:
/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d
-> /var/log/radius/radacct/10.128.5.1/auth-detail-20150408
[auth_log]
/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d
expands to /var/log/radius/radacct/10.128.5.1/auth-detail-20150408
[auth_log]     expand: %t -> Wed Apr  8 09:11:33 2015
++[auth_log] = ok
++[mschap] = noop
[eap] EAP packet type response id 4 length 6
[eap] Continuing tunnel setup.
++[eap] = ok
+} # group authorize = ok
Found Auth-Type = EAP
# Executing group from file /etc/raddb/sites-enabled/default
+group authenticate {
[eap] Request found, released from the list
[eap] EAP/peap
[eap] 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] = handled
+} # group authenticate = handled
Sending Access-Challenge of id 107 to 10.128.5.1 port 1645
    EAP-Message =
0x010503fc1940a003020102020900ebf6479ecc13e59d300d06092a864886f70d0101050500308193310b3009060355040613024652310f300d060355040813065261646975733112301006035504071309536f6d65776865726531153013060355040a130c4578616d706c6520496e632e3120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d312630240603550403131d4578616d706c6520436572746966696361746520417574686f72697479301e170d3134313130353231353435345a170d3135303130343231353435345a308193310b3009060355040613024652310f300d0603550408130652616469757331

    EAP-Message =
0x12301006035504071309536f6d65776865726531153013060355040a130c4578616d706c6520496e632e3120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d312630240603550403131d4578616d706c6520436572746966696361746520417574686f7269747930820122300d06092a864886f70d01010105000382010f003082010a0282010100b88d97967839058840e9074fde6afe5d23f7b77bb5d4c6c062c222f085626de7db03eed8672e37d56e7c7bbfbd1e68481bc526f5a0a0c88fb66eca809822cdd8cf6af8ca055f8a68f5ef4564d02f3bf64cf993ac3c3d295892f6307e88c7be325f8e295ec12610e3

    EAP-Message =
0xf442768063f2c53a36a82ce16bca9bbdf35bdba6b20073d159543d7e179817db0a67737df59b88add8091a8bb44c3278e74c08f81d1a24c45a1707d09c76cd190460958b62197f8a1bf548f5f9aeb57f7ad52761f4716ab4c0dfb2afd6c80fd90fc437e6c0db15bc2b6cdfcde709b7b1c6e9759e1e7fd546d0d271e0f8b1ff825aac83857fa1ea7e4b8f5faa691751067923655c88964fcb0203010001a381fb3081f8301d0603551d0e0416041465a61d270505d0f4781e56c2ebf2d1ddc92a82063081c80603551d230481c03081bd801465a61d270505d0f4781e56c2ebf2d1ddc92a8206a18199a48196308193310b300906035504061302465231

    EAP-Message =
0x0f300d060355040813065261646975733112301006035504071309536f6d65776865726531153013060355040a130c4578616d706c6520496e632e3120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d312630240603550403131d4578616d706c6520436572746966696361746520417574686f72697479820900ebf6479ecc13e59d300c0603551d13040530030101ff300d06092a864886f70d010105050003820101004c80773db9ef6312a280163ccfb62080bed265fd1d611fa2a065c5943f1db7ca42e4191f219277ad506c7c3d30f35a190cc5bd1ccbb67022488c049d79f4e8202e11678b49ee69dd76bee6

    EAP-Message = 0x0419550efe88be07
    Message-Authenticator = 0x00000000000000000000000000000000
    State = 0x38b508823ab0118958da8558fbdf02b8
Finished request 2.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.128.5.1 port 1645, id=108,
length=149
    User-Name = "testsim"
    Framed-MTU = 1400
    Called-Station-Id = "001d.a282.dda0"
    Calling-Station-Id = "0021.5c5b.8ef3"
    Service-Type = Login-User
    Message-Authenticator = 0xd144adfadde8e4cce83c013d1698e37b
    EAP-Message = 0x020500061900
    NAS-Port-Type = Wireless-802.11
    NAS-Port = 7538
    State = 0x38b508823ab0118958da8558fbdf02b8
    NAS-IP-Address = 10.128.5.1
    NAS-Identifier = "nas1"
# Executing section authorize from file /etc/raddb/sites-enabled/default
+group authorize {
++? if (!(User-Name =~
/^([^@]*)@(([-A-Z0-9]+\.)*[-A-Z0-9]+(\\.[-A-Z0-9]+)+)$/i))
?? Evaluating (User-Name =~
/^([^@]*)@(([-A-Z0-9]+\.)*[-A-Z0-9]+(\\.[-A-Z0-9]+)+)$/i) -> TRUE
? Converting !TRUE -> FALSE
++? if (!(User-Name =~
/^([^@]*)@(([-A-Z0-9]+\.)*[-A-Z0-9]+(\\.[-A-Z0-9]+)+)$/i)) -> FALSE
++else else {
+++update request {
    expand: %{1} -> testsim
    expand: %{2} -> example.com
+++} # update request = noop
+++? if (Realm == "example.com")
? Evaluating (Realm == "example.com") -> TRUE
+++? if (Realm == "example.com") -> TRUE
+++if (Realm == "example.com") {
++++update control {
++++} # update control = noop
+++} # if (Realm == "example.com") = noop
+++ ... skipping else for request 3: Preceding "if" was taken
++} # else else = noop
++[preprocess] = ok
[auth_log]     expand: %{Packet-Src-IP-Address} -> 10.128.5.1
[auth_log]     expand:
/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d
-> /var/log/radius/radacct/10.128.5.1/auth-detail-20150408
[auth_log]
/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d
expands to /var/log/radius/radacct/10.128.5.1/auth-detail-20150408
[auth_log]     expand: %t -> Wed Apr  8 09:11:33 2015
++[auth_log] = ok
++[mschap] = noop
[eap] EAP packet type response id 5 length 6
[eap] Continuing tunnel setup.
++[eap] = ok
+} # group authorize = ok
Found Auth-Type = EAP
# Executing group from file /etc/raddb/sites-enabled/default
+group authenticate {
[eap] Request found, released from the list
[eap] EAP/peap
[eap] 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] = handled
+} # group authenticate = handled
Sending Access-Challenge of id 108 to 10.128.5.1 port 1645
    EAP-Message =
0x010600bc190041272a2350e3d6c24837dc0dbeb6e38b25a4ef6a30dd86b675003ab0caf1e67a8fd59bf978b5a7a7cfd80884010333063b092a16ba58e339ddaffe55a835f75524219202ab6440731dafebb7c70dc3c4a49fe5302bf993adefb6e23a00619553a65807db09b4c3ca67d12fa32d6dc1f307ab4b39ac8a7b3bb4dc7a20d43d08feef956d5f96c50612ad5b7e90e305b2d42d29305e7a4c8ee180574730b0baa1fff7ddaa8ea5cf2d7abda4972f1f16030100040e000000

    Message-Authenticator = 0x00000000000000000000000000000000
    State = 0x38b508823bb3118958da8558fbdf02b8
Finished request 3.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.128.5.1 port 1645, id=109,
length=481
    User-Name = "testsim"
    Framed-MTU = 1400
    Called-Station-Id = "001d.a282.dda0"
    Calling-Station-Id = "0021.5c5b.8ef3"
    Service-Type = Login-User
    Message-Authenticator = 0x6ad947dafb13c1fd077732298e4b7d37
    EAP-Message =
0x020601501980000001461603010106100001020100c0855ad6963944aaac282dba4a7aa1393c10fd0ce3a968b68e50f742ec856a77c5fc907b48b9692a91493885eedc113cb99bfe4bf501a98d45ef499e6c563c852f14c1c422d61e105fdb7f0eb8ce30e1738bd47973e20fefa688bd4a5b41073ade45e6de36a557e18a24b158b636c5addd373e137b102a9a34ca0d75766009090eb179c521b4d4250753f6d47c1b42cf873ff1b22ae582a1e8a1f7d346880cff7226ee433de818f90d4350f8e64d7ba35b17ecad97d5e2b08e7332046756f31adf0b2b40f98cbd63c597cc490e3d2cc915ba85605e45ec7bc5db76fedea5ee1500c216daba9fa6e1

    EAP-Message =
0x6611a42bd84401f6b8d0015d9be898e9f1bce6b61bfc644f14030100010116030100301b0ab35d319a145bcab24beacd84bcced373bea44e18c153308d1406399b3df4098de3ad73546fd1554dfd99c1ad61ee

    NAS-Port-Type = Wireless-802.11
    NAS-Port = 7538
    State = 0x38b508823bb3118958da8558fbdf02b8
    NAS-IP-Address = 10.128.5.1
    NAS-Identifier = "nas1"
# Executing section authorize from file /etc/raddb/sites-enabled/default
+group authorize {
++? if (!(User-Name =~
/^([^@]*)@(([-A-Z0-9]+\.)*[-A-Z0-9]+(\\.[-A-Z0-9]+)+)$/i))
?? Evaluating (User-Name =~
/^([^@]*)@(([-A-Z0-9]+\.)*[-A-Z0-9]+(\\.[-A-Z0-9]+)+)$/i) -> TRUE
? Converting !TRUE -> FALSE
++? if (!(User-Name =~
/^([^@]*)@(([-A-Z0-9]+\.)*[-A-Z0-9]+(\\.[-A-Z0-9]+)+)$/i)) -> FALSE
++else else {
+++update request {
    expand: %{1} -> testsim
    expand: %{2} -> example.com
+++} # update request = noop
+++? if (Realm == "example.com")
? Evaluating (Realm == "example.com") -> TRUE
+++? if (Realm == "example.com") -> TRUE
+++if (Realm == "example.com") {
++++update control {
++++} # update control = noop
+++} # if (Realm == "example.com") = noop
+++ ... skipping else for request 4: Preceding "if" was taken
++} # else else = noop
++[preprocess] = ok
[auth_log]     expand: %{Packet-Src-IP-Address} -> 10.128.5.1
[auth_log]     expand:
/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d
-> /var/log/radius/radacct/10.128.5.1/auth-detail-20150408
[auth_log]
/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d
expands to /var/log/radius/radacct/10.128.5.1/auth-detail-20150408
[auth_log]     expand: %t -> Wed Apr  8 09:11:33 2015
++[auth_log] = ok
++[mschap] = noop
[eap] EAP packet type response id 6 length 253
[eap] Continuing tunnel setup.
++[eap] = ok
+} # group authorize = ok
Found Auth-Type = EAP
# Executing group from file /etc/raddb/sites-enabled/default
+group authenticate {
[eap] Request found, released from the list
[eap] EAP/peap
[eap] processing type peap
[peap] processing EAP-TLS
  TLS Length 326
[peap] Length Included
[peap] eaptls_verify returned 11
[peap] <<< TLS 1.0 Handshake [length 0106], 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] = handled
+} # group authenticate = handled
Sending Access-Challenge of id 109 to 10.128.5.1 port 1645
    EAP-Message =
0x0107004119001403010001011603010030accff4ce315827419d06c207ba18d8d916a0fa11515675cd49d414e420a9a0930d9fe9688ae81d7a0155be33b0e58838

    Message-Authenticator = 0x00000000000000000000000000000000
    State = 0x38b508823cb2118958da8558fbdf02b8
Finished request 4.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.128.5.1 port 1645, id=110,
length=149
    User-Name = "testsim"
    Framed-MTU = 1400
    Called-Station-Id = "001d.a282.dda0"
    Calling-Station-Id = "0021.5c5b.8ef3"
    Service-Type = Login-User
    Message-Authenticator = 0xc6ab797fd11fdd05ae4e2a11bc2e4446
    EAP-Message = 0x020700061900
    NAS-Port-Type = Wireless-802.11
    NAS-Port = 7538
    State = 0x38b508823cb2118958da8558fbdf02b8
    NAS-IP-Address = 10.128.5.1
    NAS-Identifier = "nas1"
# Executing section authorize from file /etc/raddb/sites-enabled/default
+group authorize {
++? if (!(User-Name =~
/^([^@]*)@(([-A-Z0-9]+\.)*[-A-Z0-9]+(\\.[-A-Z0-9]+)+)$/i))
?? Evaluating (User-Name =~
/^([^@]*)@(([-A-Z0-9]+\.)*[-A-Z0-9]+(\\.[-A-Z0-9]+)+)$/i) -> TRUE
? Converting !TRUE -> FALSE
++? if (!(User-Name =~
/^([^@]*)@(([-A-Z0-9]+\.)*[-A-Z0-9]+(\\.[-A-Z0-9]+)+)$/i)) -> FALSE
++else else {
+++update request {
    expand: %{1} -> testsim
    expand: %{2} -> example.com
+++} # update request = noop
+++? if (Realm == "example.com")
? Evaluating (Realm == "example.com") -> TRUE
+++? if (Realm == "example.com") -> TRUE
+++if (Realm == "example.com") {
++++update control {
++++} # update control = noop
+++} # if (Realm == "example.com") = noop
+++ ... skipping else for request 5: Preceding "if" was taken
++} # else else = noop
++[preprocess] = ok
[auth_log]     expand: %{Packet-Src-IP-Address} -> 10.128.5.1
[auth_log]     expand:
/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d
-> /var/log/radius/radacct/10.128.5.1/auth-detail-20150408
[auth_log]
/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d
expands to /var/log/radius/radacct/10.128.5.1/auth-detail-20150408
[auth_log]     expand: %t -> Wed Apr  8 09:11:33 2015
++[auth_log] = ok
++[mschap] = noop
[eap] EAP packet type response id 7 length 6
[eap] Continuing tunnel setup.
++[eap] = ok
+} # group authorize = ok
Found Auth-Type = EAP
# Executing group from file /etc/raddb/sites-enabled/default
+group authenticate {
[eap] Request found, released from the list
[eap] EAP/peap
[eap] 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] = handled
+} # group authenticate = handled
Sending Access-Challenge of id 110 to 10.128.5.1 port 1645
    EAP-Message =
0x0108002b190017030100207f5076412d840b25df942b4ea7ed02615832f1f49b6c178a85694c3a983ef7b2

    Message-Authenticator = 0x00000000000000000000000000000000
    State = 0x38b508823dbd118958da8558fbdf02b8
Finished request 5.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.128.5.1 port 1645, id=111,
length=202
    User-Name = "testsim"
    Framed-MTU = 1400
    Called-Station-Id = "001d.a282.dda0"
    Calling-Station-Id = "0021.5c5b.8ef3"
    Service-Type = Login-User
    Message-Authenticator = 0x4f00c3e5a991cb5c653be0c2e7e65ae3
    EAP-Message =
0x0208003b190017030100304090b9f5a031fc57489937019704d46ec9509371b82f6a394a0f0b8688d6f5b47cf5d89d7c611cc240a5cd1fb426c2f8

    NAS-Port-Type = Wireless-802.11
    NAS-Port = 7538
    State = 0x38b508823dbd118958da8558fbdf02b8
    NAS-IP-Address = 10.128.5.1
    NAS-Identifier = "nas1"
# Executing section authorize from file /etc/raddb/sites-enabled/default
+group authorize {
++? if (!(User-Name =~
/^([^@]*)@(([-A-Z0-9]+\.)*[-A-Z0-9]+(\\.[-A-Z0-9]+)+)$/i))
?? Evaluating (User-Name =~
/^([^@]*)@(([-A-Z0-9]+\.)*[-A-Z0-9]+(\\.[-A-Z0-9]+)+)$/i) -> TRUE
? Converting !TRUE -> FALSE
++? if (!(User-Name =~
/^([^@]*)@(([-A-Z0-9]+\.)*[-A-Z0-9]+(\\.[-A-Z0-9]+)+)$/i)) -> FALSE
++else else {
+++update request {
    expand: %{1} -> testsim
    expand: %{2} -> example.com
+++} # update request = noop
+++? if (Realm == "example.com")
? Evaluating (Realm == "example.com") -> TRUE
+++? if (Realm == "example.com") -> TRUE
+++if (Realm == "example.com") {
++++update control {
++++} # update control = noop
+++} # if (Realm == "example.com") = noop
+++ ... skipping else for request 6: Preceding "if" was taken
++} # else else = noop
++[preprocess] = ok
[auth_log]     expand: %{Packet-Src-IP-Address} -> 10.128.5.1
[auth_log]     expand:
/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d
-> /var/log/radius/radacct/10.128.5.1/auth-detail-20150408
[auth_log]
/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d
expands to /var/log/radius/radacct/10.128.5.1/auth-detail-20150408
[auth_log]     expand: %t -> Wed Apr  8 09:11:33 2015
++[auth_log] = ok
++[mschap] = noop
[eap] EAP packet type response id 8 length 59
[eap] Continuing tunnel setup.
++[eap] = ok
+} # group authorize = ok
Found Auth-Type = EAP
# Executing group from file /etc/raddb/sites-enabled/default
+group authenticate {
[eap] Request found, released from the list
[eap] EAP/peap
[eap] 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 - testsim
[peap] Got inner identity 'testsim'
[peap] Setting default EAP type for tunneled EAP session.
[peap] Got tunneled request
    EAP-Message = 0x02080012016e656d616e64694068692e6973
server  {
[peap] Setting User-Name to testsim
Sending tunneled request
    EAP-Message = 0x02080012016e656d616e64694068692e6973
    FreeRADIUS-Proxied-To = 127.0.0.1
    User-Name = "testsim"
    Framed-MTU = 1400
    Called-Station-Id = "001d.a282.dda0"
    Calling-Station-Id = "0021.5c5b.8ef3"
    Service-Type = Login-User
    NAS-Port-Type = Wireless-802.11
    NAS-Port = 7538
    NAS-IP-Address = 10.128.5.1
    NAS-Identifier = "nas1"
server inner-tunnel {
# Executing section authorize from file
/etc/raddb/sites-enabled/inner-tunnel
+group authorize {
++? if (!(User-Name =~
/^([^@]*)@(([-A-Z0-9]+\.)*[-A-Z0-9]+(\\.[-A-Z0-9]+)+)$/i))
?? Evaluating (User-Name =~
/^([^@]*)@(([-A-Z0-9]+\.)*[-A-Z0-9]+(\\.[-A-Z0-9]+)+)$/i) -> TRUE
? Converting !TRUE -> FALSE
++? if (!(User-Name =~
/^([^@]*)@(([-A-Z0-9]+\.)*[-A-Z0-9]+(\\.[-A-Z0-9]+)+)$/i)) -> FALSE
++else else {
+++update request {
    expand: %{1} -> testsim
    expand: %{2} -> example.com
+++} # update request = noop
+++? if (Realm == "example.com")
? Evaluating (Realm == "example.com") -> TRUE
+++? if (Realm == "example.com") -> TRUE
+++if (Realm == "example.com") {
++++update control {
++++} # update control = noop
+++} # if (Realm == "example.com") = noop
+++ ... skipping else for request 6: Preceding "if" was taken
++} # else else = noop
++[chap] = noop
++[mschap] = noop
++update control {
++} # update control = noop
[eap] EAP packet type response id 8 length 18
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] = updated
++[files] = noop
[ldap] performing user authorization for testsim
[ldap]     expand: %{Stripped-User-Name} -> testsim
[ldap]     expand: (uid=%{%{Stripped-User-Name}:-%{User-Name}}) ->
(uid=testsim)
[ldap]     expand: dc=example,dc=com -> dc=example,dc=com
  [ldap] ldap_get_conn: Checking Id: 0
  [ldap] ldap_get_conn: Got Id: 0
  [ldap] performing search in dc=example,dc=com, with filter (uid=testsim)
[ldap] looking for check items in directory...
  [ldap] gidnumber -> gidnumber == 151
[ldap] 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] ldap_release_conn: Release Id: 0
++[ldap] = ok
++[expiration] = noop
++[logintime] = noop
++[pap] = noop
+} # group authorize = updated
Found Auth-Type = EAP
# Executing group from file /etc/raddb/sites-enabled/inner-tunnel
+group authenticate {
[eap] EAP Identity
[eap] processing type mschapv2
rlm_eap_mschapv2: Issuing Challenge
++[eap] = handled
+} # group authenticate = handled
} # server inner-tunnel
[peap] Got tunneled reply code 11
    EAP-Message =
0x010900271a0109002210f41316a03b1084792a800927517e5cba6e656d616e64694068692e6973

    Message-Authenticator = 0x00000000000000000000000000000000
    State = 0x416c26a841653c1af7524cb85ac3e0bd
[peap] Got tunneled reply RADIUS code 11
    EAP-Message =
0x010900271a0109002210f41316a03b1084792a800927517e5cba6e656d616e64694068692e6973

    Message-Authenticator = 0x00000000000000000000000000000000
    State = 0x416c26a841653c1af7524cb85ac3e0bd
[peap] Got tunneled Access-Challenge
++[eap] = handled
+} # group authenticate = handled
Sending Access-Challenge of id 111 to 10.128.5.1 port 1645
    EAP-Message =
0x0109004b190017030100401f6d43ea2501dbe7c50242a48134e0ebb8e6caaa214b21f300eeea5729ebd08306607fa84d197690f7c1e9f89f8cef38c4c67eaa77ee402f86a60de0eca33936

    Message-Authenticator = 0x00000000000000000000000000000000
    State = 0x38b508823ebc118958da8558fbdf02b8
Finished request 6.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.128.5.1 port 1645, id=112,
length=250
    User-Name = "testsim"
    Framed-MTU = 1400
    Called-Station-Id = "001d.a282.dda0"
    Calling-Station-Id = "0021.5c5b.8ef3"
    Service-Type = Login-User
    Message-Authenticator = 0xc2e0f0d369e12690595070cd22bc2cfe
    EAP-Message =
0x0209006b190017030100609e2f696eba76c538a37b5b364171b7179dab8f6436f7bd8691bd05979845f428aa324fc782fddec20f292c940a14dc4d95a66b8348fbb7092eb2f014b6d020d5c3dd178e93104bf0013b58f6a30ee4321f0a46e7516bce33180622acac46aed3

    NAS-Port-Type = Wireless-802.11
    NAS-Port = 7538
    State = 0x38b508823ebc118958da8558fbdf02b8
    NAS-IP-Address = 10.128.5.1
    NAS-Identifier = "nas1"
# Executing section authorize from file /etc/raddb/sites-enabled/default
+group authorize {
++? if (!(User-Name =~
/^([^@]*)@(([-A-Z0-9]+\.)*[-A-Z0-9]+(\\.[-A-Z0-9]+)+)$/i))
?? Evaluating (User-Name =~
/^([^@]*)@(([-A-Z0-9]+\.)*[-A-Z0-9]+(\\.[-A-Z0-9]+)+)$/i) -> TRUE
? Converting !TRUE -> FALSE
++? if (!(User-Name =~
/^([^@]*)@(([-A-Z0-9]+\.)*[-A-Z0-9]+(\\.[-A-Z0-9]+)+)$/i)) -> FALSE
++else else {
+++update request {
    expand: %{1} -> testsim
    expand: %{2} -> example.com
+++} # update request = noop
+++? if (Realm == "example.com")
? Evaluating (Realm == "example.com") -> TRUE
+++? if (Realm == "example.com") -> TRUE
+++if (Realm == "example.com") {
++++update control {
++++} # update control = noop
+++} # if (Realm == "example.com") = noop
+++ ... skipping else for request 7: Preceding "if" was taken
++} # else else = noop
++[preprocess] = ok
[auth_log]     expand: %{Packet-Src-IP-Address} -> 10.128.5.1
[auth_log]     expand:
/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d
-> /var/log/radius/radacct/10.128.5.1/auth-detail-20150408
[auth_log]
/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d
expands to /var/log/radius/radacct/10.128.5.1/auth-detail-20150408
[auth_log]     expand: %t -> Wed Apr  8 09:11:33 2015
++[auth_log] = ok
++[mschap] = noop
[eap] EAP packet type response id 9 length 107
[eap] Continuing tunnel setup.
++[eap] = ok
+} # group authorize = ok
Found Auth-Type = EAP
# Executing group from file /etc/raddb/sites-enabled/default
+group authenticate {
[eap] Request found, released from the list
[eap] EAP/peap
[eap] 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 phase2
[peap] EAP type mschapv2
[peap] Got tunneled request
    EAP-Message =
0x020900481a020900433102417b34194b892881043d74d81bbe870000000000000000dff0f77ea75a032abba8482ab53f3675f8566c47b63a6767006e656d616e64694068692e6973

server  {
[peap] Setting User-Name to testsim
Sending tunneled request
    EAP-Message =
0x020900481a020900433102417b34194b892881043d74d81bbe870000000000000000dff0f77ea75a032abba8482ab53f3675f8566c47b63a6767006e656d616e64694068692e6973

    FreeRADIUS-Proxied-To = 127.0.0.1
    User-Name = "testsim"
    State = 0x416c26a841653c1af7524cb85ac3e0bd
    Framed-MTU = 1400
    Called-Station-Id = "001d.a282.dda0"
    Calling-Station-Id = "0021.5c5b.8ef3"
    Service-Type = Login-User
    NAS-Port-Type = Wireless-802.11
    NAS-Port = 7538
    NAS-IP-Address = 10.128.5.1
    NAS-Identifier = "nas1"
server inner-tunnel {
# Executing section authorize from file
/etc/raddb/sites-enabled/inner-tunnel
+group authorize {
++? if (!(User-Name =~
/^([^@]*)@(([-A-Z0-9]+\.)*[-A-Z0-9]+(\\.[-A-Z0-9]+)+)$/i))
?? Evaluating (User-Name =~
/^([^@]*)@(([-A-Z0-9]+\.)*[-A-Z0-9]+(\\.[-A-Z0-9]+)+)$/i) -> TRUE
? Converting !TRUE -> FALSE
++? if (!(User-Name =~
/^([^@]*)@(([-A-Z0-9]+\.)*[-A-Z0-9]+(\\.[-A-Z0-9]+)+)$/i)) -> FALSE
++else else {
+++update request {
    expand: %{1} -> testsim
    expand: %{2} -> example.com
+++} # update request = noop
+++? if (Realm == "example.com")
? Evaluating (Realm == "example.com") -> TRUE
+++? if (Realm == "example.com") -> TRUE
+++if (Realm == "example.com") {
++++update control {
++++} # update control = noop
+++} # if (Realm == "example.com") = noop
+++ ... skipping else for request 7: Preceding "if" was taken
++} # else else = noop
++[chap] = noop
++[mschap] = noop
++update control {
++} # update control = noop
[eap] EAP packet type response id 9 length 72
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] = updated
++[files] = noop
[ldap] performing user authorization for testsim
[ldap]     expand: %{Stripped-User-Name} -> testsim
[ldap]     expand: (uid=%{%{Stripped-User-Name}:-%{User-Name}}) ->
(uid=testsim)
[ldap]     expand: dc=example,dc=com -> dc=example,dc=com
  [ldap] ldap_get_conn: Checking Id: 0
  [ldap] ldap_get_conn: Got Id: 0
  [ldap] performing search in dc=example,dc=com, with filter (uid=testsim)
[ldap] looking for check items in directory...
  [ldap] gidnumber -> gidnumber == 151
[ldap] 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] ldap_release_conn: Release Id: 0
++[ldap] = ok
++[expiration] = noop
++[logintime] = noop
++[pap] = noop
+} # group authorize = updated
Found Auth-Type = EAP
# Executing group from file /etc/raddb/sites-enabled/inner-tunnel
+group authenticate {
[eap] Request found, released from the list
[eap] EAP/mschapv2
[eap] processing type mschapv2
[mschapv2] # Executing group from file
/etc/raddb/sites-enabled/inner-tunnel
[mschapv2] +group MS-CHAP {
[mschap] Creating challenge hash with username: testsim
[mschap] Client is using MS-CHAPv2 for testsim, we need NT-Password
[mschap]     expand: %{Stripped-User-Name} -> testsim
[mschap]     expand:
--username=%{%{Stripped-User-Name}:-%{%{User-Name}:-None}} ->
--username=testsim
[mschap] Creating challenge hash with username: testsim
[mschap]     expand: %{mschap:Challenge} -> 54bd58af35832bf5
[mschap]     expand: --challenge=%{%{mschap:Challenge}:-00} ->
--challenge=54bd58af35832bf5
[mschap]     expand: %{mschap:NT-Response} ->
dff0f77ea75a032abba8482ab53f3675f8566c47b63a6767
[mschap]     expand: --nt-response=%{%{mschap:NT-Response}:-00} ->
--nt-response=dff0f77ea75a032abba8482ab53f3675f8566c47b63a6767
Exec output: NT_KEY: 04066C8C6B0E8CFCABBB0AB6760971F7
Exec plaintext: NT_KEY: 04066C8C6B0E8CFCABBB0AB6760971F7
[mschap] Exec: program returned: 0
[mschap] adding MS-CHAPv2 MPPE keys
++[mschap] = ok
+} # group MS-CHAP = ok
MSCHAP Success
++[eap] = handled
+} # group authenticate = handled
} # server inner-tunnel
[peap] Got tunneled reply code 11
    EAP-Message =
0x010a00331a0309002e533d41434442323243414238463344393845454537463933353439423239364630393539393732413544

    Message-Authenticator = 0x00000000000000000000000000000000
    State = 0x416c26a840663c1af7524cb85ac3e0bd
[peap] Got tunneled reply RADIUS code 11
    EAP-Message =
0x010a00331a0309002e533d41434442323243414238463344393845454537463933353439423239364630393539393732413544

    Message-Authenticator = 0x00000000000000000000000000000000
    State = 0x416c26a840663c1af7524cb85ac3e0bd
[peap] Got tunneled Access-Challenge
++[eap] = handled
+} # group authenticate = handled
Sending Access-Challenge of id 112 to 10.128.5.1 port 1645
    EAP-Message =
0x010a005b190017030100505abc7015e99f48aeb8a4a7fd49b81aeb80d0c2c5b24f5e2bcf0124c825dc26adb87cb1a9adf3a7762daad9825cf61016bdc1796482135a1cf7d3fdb6feb5bab4e6537baaee9dfc1a4edc7bc3693f39dc

    Message-Authenticator = 0x00000000000000000000000000000000
    State = 0x38b508823fbf118958da8558fbdf02b8
Finished request 7.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.128.5.1 port 1645, id=113,
length=186
    User-Name = "testsim"
    Framed-MTU = 1400
    Called-Station-Id = "001d.a282.dda0"
    Calling-Station-Id = "0021.5c5b.8ef3"
    Service-Type = Login-User
    Message-Authenticator = 0x0c417235948f2727bfc124946e33ab5f
    EAP-Message =
0x020a002b19001703010020184a94d5a7fa577e45fe61025a1a551b2d0b42f5f65d7f48b2cc50309cbd2d0f

    NAS-Port-Type = Wireless-802.11
    NAS-Port = 7538
    State = 0x38b508823fbf118958da8558fbdf02b8
    NAS-IP-Address = 10.128.5.1
    NAS-Identifier = "nas1"
# Executing section authorize from file /etc/raddb/sites-enabled/default
+group authorize {
++? if (!(User-Name =~
/^([^@]*)@(([-A-Z0-9]+\.)*[-A-Z0-9]+(\\.[-A-Z0-9]+)+)$/i))
?? Evaluating (User-Name =~
/^([^@]*)@(([-A-Z0-9]+\.)*[-A-Z0-9]+(\\.[-A-Z0-9]+)+)$/i) -> TRUE
? Converting !TRUE -> FALSE
++? if (!(User-Name =~
/^([^@]*)@(([-A-Z0-9]+\.)*[-A-Z0-9]+(\\.[-A-Z0-9]+)+)$/i)) -> FALSE
++else else {
+++update request {
    expand: %{1} -> testsim
    expand: %{2} -> example.com
+++} # update request = noop
+++? if (Realm == "example.com")
? Evaluating (Realm == "example.com") -> TRUE
+++? if (Realm == "example.com") -> TRUE
+++if (Realm == "example.com") {
++++update control {
++++} # update control = noop
+++} # if (Realm == "example.com") = noop
+++ ... skipping else for request 8: Preceding "if" was taken
++} # else else = noop
++[preprocess] = ok
[auth_log]     expand: %{Packet-Src-IP-Address} -> 10.128.5.1
[auth_log]     expand:
/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d
-> /var/log/radius/radacct/10.128.5.1/auth-detail-20150408
[auth_log]
/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d
expands to /var/log/radius/radacct/10.128.5.1/auth-detail-20150408
[auth_log]     expand: %t -> Wed Apr  8 09:11:33 2015
++[auth_log] = ok
++[mschap] = noop
[eap] EAP packet type response id 10 length 43
[eap] Continuing tunnel setup.
++[eap] = ok
+} # group authorize = ok
Found Auth-Type = EAP
# Executing group from file /etc/raddb/sites-enabled/default
+group authenticate {
[eap] Request found, released from the list
[eap] EAP/peap
[eap] 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 phase2
[peap] EAP type mschapv2
[peap] Got tunneled request
    EAP-Message = 0x020a00061a03
server  {
[peap] Setting User-Name to testsim
Sending tunneled request
    EAP-Message = 0x020a00061a03
    FreeRADIUS-Proxied-To = 127.0.0.1
    User-Name = "testsim"
    State = 0x416c26a840663c1af7524cb85ac3e0bd
    Framed-MTU = 1400
    Called-Station-Id = "001d.a282.dda0"
    Calling-Station-Id = "0021.5c5b.8ef3"
    Service-Type = Login-User
    NAS-Port-Type = Wireless-802.11
    NAS-Port = 7538
    NAS-IP-Address = 10.128.5.1
    NAS-Identifier = "nas1"
server inner-tunnel {
# Executing section authorize from file
/etc/raddb/sites-enabled/inner-tunnel
+group authorize {
++? if (!(User-Name =~
/^([^@]*)@(([-A-Z0-9]+\.)*[-A-Z0-9]+(\\.[-A-Z0-9]+)+)$/i))
?? Evaluating (User-Name =~
/^([^@]*)@(([-A-Z0-9]+\.)*[-A-Z0-9]+(\\.[-A-Z0-9]+)+)$/i) -> TRUE
? Converting !TRUE -> FALSE
++? if (!(User-Name =~
/^([^@]*)@(([-A-Z0-9]+\.)*[-A-Z0-9]+(\\.[-A-Z0-9]+)+)$/i)) -> FALSE
++else else {
+++update request {
    expand: %{1} -> testsim
    expand: %{2} -> example.com
+++} # update request = noop
+++? if (Realm == "example.com")
? Evaluating (Realm == "example.com") -> TRUE
+++? if (Realm == "example.com") -> TRUE
+++if (Realm == "example.com") {
++++update control {
++++} # update control = noop
+++} # if (Realm == "example.com") = noop
+++ ... skipping else for request 8: Preceding "if" was taken
++} # else else = noop
++[chap] = noop
++[mschap] = noop
++update control {
++} # update control = noop
[eap] EAP packet type response id 10 length 6
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] = updated
++[files] = noop
[ldap] performing user authorization for testsim
[ldap]     expand: %{Stripped-User-Name} -> testsim
[ldap]     expand: (uid=%{%{Stripped-User-Name}:-%{User-Name}}) ->
(uid=testsim)
[ldap]     expand: dc=example,dc=com -> dc=example,dc=com
  [ldap] ldap_get_conn: Checking Id: 0
  [ldap] ldap_get_conn: Got Id: 0
  [ldap] performing search in dc=example,dc=com, with filter (uid=testsim)
[ldap] looking for check items in directory...
  [ldap] gidnumber -> gidnumber == 151
[ldap] 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] ldap_release_conn: Release Id: 0
++[ldap] = ok
++[expiration] = noop
++[logintime] = noop
++[pap] = noop
+} # group authorize = updated
Found Auth-Type = EAP
# Executing group from file /etc/raddb/sites-enabled/inner-tunnel
+group authenticate {
[eap] Request found, released from the list
[eap] EAP/mschapv2
[eap] processing type mschapv2
[eap] Freeing handler
++[eap] = ok
+} # group authenticate = ok
Login OK: [testsim] (from client nas1.example.com port 7538 cli
0021.5c5b.8ef3 via TLS tunnel)
  WARNING: Empty post-auth section.  Using default return values.
# Executing section post-auth from file
/etc/raddb/sites-enabled/inner-tunnel
} # server inner-tunnel
[peap] Got tunneled reply code 2
    MS-MPPE-Encryption-Policy = 0x00000002
    MS-MPPE-Encryption-Types = 0x00000004
    MS-MPPE-Send-Key = 0x3199860568d097ec0b8089069fb5610b
    MS-MPPE-Recv-Key = 0x8ed3b05bfc604db44626a58eec554bac
    EAP-Message = 0x030a0004
    Message-Authenticator = 0x00000000000000000000000000000000
    User-Name = "testsim"
[peap] Got tunneled reply RADIUS code 2
    MS-MPPE-Encryption-Policy = 0x00000002
    MS-MPPE-Encryption-Types = 0x00000004
    MS-MPPE-Send-Key = 0x3199860568d097ec0b8089069fb5610b
    MS-MPPE-Recv-Key = 0x8ed3b05bfc604db44626a58eec554bac
    EAP-Message = 0x030a0004
    Message-Authenticator = 0x00000000000000000000000000000000
    User-Name = "testsim"
[peap] Tunneled authentication was successful.
[peap] SUCCESS
[peap] Saving tunneled attributes for later
++[eap] = handled
+} # group authenticate = handled
Sending Access-Challenge of id 113 to 10.128.5.1 port 1645
    EAP-Message =
0x010b002b19001703010020c6185b12fc87f757a8b064b9f14e1c7ee918a599af74dfe8a6538464604a64c4

    Message-Authenticator = 0x00000000000000000000000000000000
    State = 0x38b5088230be118958da8558fbdf02b8
Finished request 8.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.128.5.1 port 1645, id=114,
length=186
    User-Name = "testsim"
    Framed-MTU = 1400
    Called-Station-Id = "001d.a282.dda0"
    Calling-Station-Id = "0021.5c5b.8ef3"
    Service-Type = Login-User
    Message-Authenticator = 0xeea79801da2d8743312b860108e7be4f
    EAP-Message =
0x020b002b19001703010020d22b7fe9d88a5884d38d8278f349c6bac9511d9f5a0bbe7367174d10bb1d0029

    NAS-Port-Type = Wireless-802.11
    NAS-Port = 7538
    State = 0x38b5088230be118958da8558fbdf02b8
    NAS-IP-Address = 10.128.5.1
    NAS-Identifier = "nas1"
# Executing section authorize from file /etc/raddb/sites-enabled/default
+group authorize {
++? if (!(User-Name =~
/^([^@]*)@(([-A-Z0-9]+\.)*[-A-Z0-9]+(\\.[-A-Z0-9]+)+)$/i))
?? Evaluating (User-Name =~
/^([^@]*)@(([-A-Z0-9]+\.)*[-A-Z0-9]+(\\.[-A-Z0-9]+)+)$/i) -> TRUE
? Converting !TRUE -> FALSE
++? if (!(User-Name =~
/^([^@]*)@(([-A-Z0-9]+\.)*[-A-Z0-9]+(\\.[-A-Z0-9]+)+)$/i)) -> FALSE
++else else {
+++update request {
    expand: %{1} -> testsim
    expand: %{2} -> example.com
+++} # update request = noop
+++? if (Realm == "example.com")
? Evaluating (Realm == "example.com") -> TRUE
+++? if (Realm == "example.com") -> TRUE
+++if (Realm == "example.com") {
++++update control {
++++} # update control = noop
+++} # if (Realm == "example.com") = noop
+++ ... skipping else for request 9: Preceding "if" was taken
++} # else else = noop
++[preprocess] = ok
[auth_log]     expand: %{Packet-Src-IP-Address} -> 10.128.5.1
[auth_log]     expand:
/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d
-> /var/log/radius/radacct/10.128.5.1/auth-detail-20150408
[auth_log]
/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d
expands to /var/log/radius/radacct/10.128.5.1/auth-detail-20150408
[auth_log]     expand: %t -> Wed Apr  8 09:11:33 2015
++[auth_log] = ok
++[mschap] = noop
[eap] EAP packet type response id 11 length 43
[eap] Continuing tunnel setup.
++[eap] = ok
+} # group authorize = ok
Found Auth-Type = EAP
# Executing group from file /etc/raddb/sites-enabled/default
+group authenticate {
[eap] Request found, released from the list
[eap] EAP/peap
[eap] 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 success
[peap] Received EAP-TLV response.
[peap] Success
[peap] Using saved attributes from the original Access-Accept
    User-Name = "testsim"
[eap] Freeing handler
++[eap] = ok
+} # group authenticate = ok
Login OK: [testsim] (from client nas1.example.com port 7538 cli
0021.5c5b.8ef3)
# Executing section post-auth from file /etc/raddb/sites-enabled/default
+group post-auth {
[reply_log]     expand: %{Packet-Src-IP-Address} -> 10.128.5.1
[reply_log]     expand:
/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/reply-detail-%Y%m%d
-> /var/log/radius/radacct/10.128.5.1/reply-detail-20150408
[reply_log]
/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/reply-detail-%Y%m%d
expands to /var/log/radius/radacct/10.128.5.1/reply-detail-20150408
[reply_log]     expand: %t -> Wed Apr  8 09:11:33 2015
++[reply_log] = ok
+} # group post-auth = ok
Sending Access-Accept of id 114 to 10.128.5.1 port 1645
    User-Name = "testsim"
    MS-MPPE-Recv-Key =
0xc5724eecd3d9ebd751e4bae7d4f070f3264a20196e19181964da1fff44e79f99
    MS-MPPE-Send-Key =
0x8fd0954dc019958a63e488fb2005626af52042e7dd3e762921b5f2e154bab542
    EAP-Message = 0x030b0004
    Message-Authenticator = 0x00000000000000000000000000000000
Finished request 9.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Accounting-Request packet from host 10.128.5.1 port 1646, id=196,
length=113
    Acct-Session-Id = "00001D62"
    Called-Station-Id = "001d.a282.dda0"
    Calling-Station-Id = "0021.5c5b.8ef3"
    User-Name = "testsim"
    Acct-Authentic = RADIUS
    Acct-Status-Type = Start
    NAS-Port-Type = Wireless-802.11
    NAS-Port = 7538
    Service-Type = Framed-User
    NAS-IP-Address = 10.128.5.1
    Acct-Delay-Time = 0
# Executing section preacct from file /etc/raddb/sites-enabled/default
+group preacct {
++[preprocess] = ok
[acct_unique] WARNING: Attribute NAS-Identifier was not found in request,
unique ID MAY be inconsistent
[acct_unique] Hashing 'NAS-Port = 7538,,NAS-IP-Address =
10.128.5.1,Acct-Session-Id = "00001D62",User-Name = "testsim"'
[acct_unique] Acct-Unique-Session-ID = "6eae5b5c386e2bcd".
++[acct_unique] = ok
++[files] = noop
+} # group preacct = ok
# Executing section accounting from file /etc/raddb/sites-enabled/default
+group accounting {
[detail]     expand: %{Packet-Src-IP-Address} -> 10.128.5.1
[detail]     expand:
/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d
-> /var/log/radius/radacct/10.128.5.1/detail-20150408
[detail]
/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d
expands to /var/log/radius/radacct/10.128.5.1/detail-20150408
[detail]     expand: %t -> Wed Apr  8 09:11:33 2015
++[detail] = ok
[sql]     expand: %{Stripped-User-Name} ->
[sql]     ... expanding second conditional
[sql]     expand: %{User-Name} -> testsim
[sql]     expand: %{%{User-Name}:-DEFAULT} -> testsim
[sql]     expand: %{%{Stripped-User-Name}:-%{%{User-Name}:-DEFAULT}} ->
testsim
[sql] sql_set_user escaped user --> 'testsim'
[sql]     expand: %{Acct-Delay-Time} -> 0
[sql]     expand:            INSERT INTO radacct
(acctsessionid,    acctuniqueid,     username,
realm,            nasipaddress,     nasportid,
nasporttype,      acctstarttime,    acctstoptime,
acctsessiontime,  acctauthentic,    connectinfo_start,
connectinfo_stop, acctinputoctets,  acctoutputoctets,
calledstationid,  callingstationid, acctterminatecause,
servicetype,      framedprotocol,   framedipaddress,
acctstartdelay,   acctstopdelay,    xascendsessionsvrkey)
VALUES             ('%{Acct-Session-Id}',
'%{Acct-Unique-Session-Id}',              '%{SQL-User-Name}',
'%{Realm}', '%{NAS-IP-Address}', '%{NAS-Port}',
'%{NAS-Port-Type}', '%S', NULL,              '0', '%{Acct-Authentic}',
'%{Connect-Info}',              '', '0', '0',
'%{Called-Station-Id}', '%{Calling-Station-Id}', '',
'%{Service-Type}', '%{Framed-Protocol}', '%{Framed-IP-Address}',
rlm_sql (sql): Reserving sql socket id: 31
rlm_sql (sql): Released sql socket id: 31
++[sql] = ok
[attr_filter.accounting_response]     expand: %{User-Name} -> testsim
attr_filter: Matched entry DEFAULT at line 12
++[attr_filter.accounting_response] = updated
+} # group accounting = updated
Sending Accounting-Response of id 196 to 10.128.5.1 port 1646
Finished request 10.
Cleaning up request 10 ID 196 with timestamp +7
Going to the next request
Waking up in 4.8 seconds.
Cleaning up request 0 ID 105 with timestamp +7
Cleaning up request 1 ID 106 with timestamp +7
Cleaning up request 2 ID 107 with timestamp +7
Cleaning up request 3 ID 108 with timestamp +7
Cleaning up request 4 ID 109 with timestamp +7
Cleaning up request 5 ID 110 with timestamp +7
Cleaning up request 6 ID 111 with timestamp +7
Cleaning up request 7 ID 112 with timestamp +7
Cleaning up request 8 ID 113 with timestamp +7
Cleaning up request 9 ID 114 with timestamp +7
Ready to process requests.







On Tue, Apr 7, 2015 at 3:41 PM, Alan DeKok <aland at deployingradius.com>
wrote:

> On Apr 7, 2015, at 11:16 AM, Khapare Joshi <khapare77 at gmail.com> wrote:
> > I have tried today with simualtaneous-Use with gidnumber, here are what I
> > did.
>
>   That all looks fine.
>
> > # check gid for simultaneous use
> >
> > if ("%{gidnumber}" < 200){
>
>   That's not necessary.  You should just do:
>
>         if (gidnumber < 200) {
>                 ...
>
>   And PLEASE cut & paste these examples in the email.  Do NOT rewrite
> them.  The example you gave has syntax errors.  It should be:
>
>
> if (gidnumber < 200){
>    update request {
>      Simultaneous-Use := 1
>     }
> }
>  else{
>     update request {
>        Simultaneous-Use := 2
>     }
> }
>
> > the regex checking returns true for user testsim who has gid less than
> 200
>
>   It's not a regex check.  This MATTERS.  If you don't use the right
> terminology, you'll never understand what's going on, and you'll never be
> able to fix it.
>
> > but testsim still able to login 2nd and 3rd login.
> >
> > can anyone see what I am missing ?
> >
> > here is the debug output
>
>   Which includes:
>
> (1) a long EAP session.  Users can log in.  We don't need to see this.
>
> (2) ONE accounting packet.  We already know that users can log in once.
>
>   It does NOT include a login session where the user CAN log in, but
> should not be able to.  Since you're not looking at that, you don't really
> know what's going wrong.  And you'll never be able to solve the problem.
>
>   You need to take a methodical approach to solve this issue.  Have a user
> log in once, and save that debug output.  Have them log in again.  Save
> that debug output.  Then, compare the two to see why they differ.  Be sure
> that users can login when they're supposed to, and are rejected when they
> should be rejected.
>
>   Alan DeKok.
>
>
> -
> List info/subscribe/unsubscribe? See
> http://www.freeradius.org/list/users.html
>


More information about the Freeradius-Users mailing list