Simultaneous-Use Checking with FreeRadius + MYSQL

8 Nov 2011

      -----------------------------------------
FreeRadius Version: 2.1.10
-----------------------------------------

Hello All,
I've been going in circles for days on how to come up with a
workaround to get simultaneous-use checking working on my FreeRadius +
PEAP MSCHAPv2 deployment.  I have read through seemingly all of the
posts...  I suspect certain areas which might be causing the problem:
1) my NAS does not seem to be sending accounting information.  The
radacct table is empty & this is also visible in the debugs.  There is
no area to set up RADIUS accounting on the NAS (it's a cheap netgear)
and it doesn't appear to send accounting packets by default.
2) "checkrad.pl" is not being called automatically when no accounting
data is being returned by "simul_count_query".  I have the NAS type
set to "cisco" to trigger checkrad.pl for troubleshooting purposes,
but it doesn't seem to do any good.

First of all - is it possible to do simultaneous-use checking if the
NAS doesn't send radius accounting packets?  Can the radius server
somehow autonomously keep track of this without packets from the NAS?

If not, is there another application which will fulfill this function?
 Do I need to move to radutmp?

Any input and guidance would be greatly appreciated.  Details are below.

thanks in advance!

Erik

==========================================
RELEVANT CONFIGURATIONS (some output omitted):
------------------------------------------------------------------------------------
------------------------------------------
/etc/freeradius/radiusd.conf

modules {
$INCLUDE sql.conf
$INCLUDE sql/mysql/counter.conf
}

------------------------------------------
/etc/freeradius/sql/mysql/dialup.conf

       simul_count_query = "SELECT COUNT(*) \
                            #FROM ${acct_table1} \
                            #WHERE username = '%{SQL-User-Name}' \
                            #AND acctstoptime IS NULL"

#       simul_verify_query  = "SELECT radacctid, acctsessionid, username, \
                              nasipaddress, nasportid, framedipaddress, \
                              callingstationid, framedprotocol \
                              FROM ${acct_table1} \
                              WHERE username = '%{SQL-User-Name}' \
                              AND acctstoptime IS NULL"
------------------------------------------
/etc/freeradius/sites-available/default

authorize {
       #sql is the first option in the authorize list.
       sql
}

accounting {
       #  For Simultaneous-Use tracking.
       #
       #  Due to packet losses in the network, the data here
       #  may be incorrect.  There is little we can do about it.
#       radutmp
#       sradutmp
}

session {
#       radutmp

       #
       #  See "Simultaneous Use Checking Queries" in sql.conf
       sql
}

post-auth {
sql
}

------------------------------------------
/etc/freeradius/sites-available/inner-tunnel

authorize {
       #sql is the first option in the authorize list.
       sql
}

# *** THERE IS NO ACCOUNTING SECTION***

session {
#       radutmp

       #
       #  See "Simultaneous Use Checking Queries" in sql.conf
       sql
}

post-auth {
sql
}

==================
MYSQL INFO:
------------------------------------
mysql> SELECT * FROM radgroupcheck;
+----+---------------------------+------------------+----+--------+
| id | groupname                 | attribute        | op | value  |
+----+---------------------------+------------------+----+--------+
|  1 | daloRADIUS-Disabled-Users | Auth-Type        | := | Reject |
|  3 | sandruid-ap-wifi          | Simultaneous-Use | := | 1      |
+----+---------------------------+------------------+----+--------+

mysql> SELECT * FROM radusergroup;
+----------+------------------+----------+
| username | groupname        | priority |
+----------+------------------+----------+
| lynnae   | sandruid-ap-wifi |        0 |
+----------+------------------+----------+
1 row in set (0.00 sec)

mysql> SELECT * FROM nas;
+----+---------------+------------------+-------+-------+--------+--------+-----------+-------------+
| id | nasname       | shortname        | type  | ports | secret |
server | community | description |
+----+---------------+------------------+-------+-------+--------+--------+-----------+-------------+
|  5 | 192.168.2.254 | sandruid-ap-wifi | cisco |     0 | xxxx | NULL
 |           |             |
+----+---------------+------------------+-------+-------+--------+--------+-----------+-------------+
5 rows in set (0.00 sec)

==================
freeradius -X DEBUG:
------------------------------------

Ready to process requests.
rad_recv: Access-Request packet from host 192.168.2.254 port 2060,
id=118, length=149
        User-Name = "lynnae"
        NAS-IP-Address = 192.168.2.254
        NAS-Port = 0
        Called-Station-Id = "30-46-9A-0E-B4-DF:druid"
        Calling-Station-Id = "7C-61-93-9E-3A-D9"
        Framed-MTU = 1400
        NAS-Port-Type = Wireless-802.11
        Connect-Info = "CONNECT 0Mbps 802.11"
        EAP-Message = 0x0200000b016c796e6e6165
        Message-Authenticator = 0x8c1acd761b639cf66ea60d2d7f512b4b
# Executing section authorize from file /etc/freeradius/sites-enabled/default
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
++[digest] returns noop
[suffix] No '@' in User-Name = "lynnae", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 0 length 11
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
++[files] returns noop
[sql]   expand: %{User-Name} -> lynnae
[sql] sql_set_user escaped user --> 'lynnae'
rlm_sql (sql): Reserving sql socket id: 4
[sql]   expand: SELECT id, username, attribute, value, op
FROM radcheck           WHERE username = '%{SQL-User-Name}'
ORDER BY id -> SELECT id, username, attribute, value, op
FROM radcheck           WHERE username = 'lynnae'           ORDER BY
id
rlm_sql_mysql: query:  SELECT id, username, attribute, value, op
    FROM radcheck           WHERE username = 'lynnae'           ORDER
BY id
[sql] User found in radcheck table
[sql]   expand: SELECT id, username, attribute, value, op
FROM radreply           WHERE username = '%{SQL-User-Name}'
ORDER BY id -> SELECT id, username, attribute, value, op
FROM radreply           WHERE username = 'lynnae'           ORDER BY
id
rlm_sql_mysql: query:  SELECT id, username, attribute, value, op
    FROM radreply           WHERE username = 'lynnae'           ORDER
BY id
[sql]   expand: SELECT groupname           FROM radusergroup
WHERE username = '%{SQL-User-Name}'           ORDER BY priority ->
SELECT groupname           FROM radusergroup           WHERE username
= 'lynnae'           ORDER BY priority
rlm_sql_mysql: query:  SELECT groupname           FROM radusergroup
       WHERE username = 'lynnae'           ORDER BY priority
[sql]   expand: SELECT id, groupname, attribute,           Value, op
        FROM radgroupcheck           WHERE groupname = '%{Sql-Group}'
         ORDER BY id -> SELECT id, groupname, attribute,
Value, op           FROM radgroupcheck           WHERE groupname =
'sandruid-ap-wifi'           ORDER BY id
rlm_sql_mysql: query:  SELECT id, groupname, attribute,
Value, op           FROM radgroupcheck           WHERE groupname =
'sandruid-ap-wifi'           ORDER BY id
[sql] User found in group sandruid-ap-wifi
[sql]   expand: SELECT id, groupname, attribute,           value, op
        FROM radgroupreply           WHERE groupname = '%{Sql-Group}'
         ORDER BY id -> SELECT id, groupname, attribute,
value, op           FROM radgroupreply           WHERE groupname =
'sandruid-ap-wifi'           ORDER BY id
rlm_sql_mysql: query:  SELECT id, groupname, attribute,
value, op           FROM radgroupreply           WHERE groupname =
'sandruid-ap-wifi'           ORDER BY id
rlm_sql (sql): Released sql socket id: 4
++[sql] returns ok
++[expiration] returns noop
++[logintime] returns noop
[pap] WARNING: Auth-Type already set.  Not setting to PAP
++[pap] returns noop
Found Auth-Type = EAP
# Executing group from file /etc/freeradius/sites-enabled/default
+- entering group authenticate {...}
[eap] EAP Identity
[eap] processing type md5
rlm_eap_md5: Issuing Challenge
++[eap] returns handled
Sending Access-Challenge of id 118 to 192.168.2.254 port 2060
        EAP-Message = 0x010100160410e2f76fece48e6e2f4257c55e4d843858
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x9157e73c9156e36f0d908f26ca869d55
Finished request 157.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 192.168.2.254 port 2060,
id=119, length=162
        User-Name = "lynnae"
        NAS-IP-Address = 192.168.2.254
        NAS-Port = 0
        Called-Station-Id = "30-46-9A-0E-B4-DF:druid"
        Calling-Station-Id = "7C-61-93-9E-3A-D9"
        Framed-MTU = 1400
        NAS-Port-Type = Wireless-802.11
        Connect-Info = "CONNECT 0Mbps 802.11"
        EAP-Message = 0x020100060319
        State = 0x9157e73c9156e36f0d908f26ca869d55
        Message-Authenticator = 0x3662b294c2a55a1a6a4a428d5d35c2ea
# Executing section authorize from file /etc/freeradius/sites-enabled/default
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
++[digest] returns noop
[suffix] No '@' in User-Name = "lynnae", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 1 length 6
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
++[files] returns noop
[sql]   expand: %{User-Name} -> lynnae
[sql] sql_set_user escaped user --> 'lynnae'
rlm_sql (sql): Reserving sql socket id: 3
[sql]   expand: SELECT id, username, attribute, value, op
FROM radcheck           WHERE username = '%{SQL-User-Name}'
ORDER BY id -> SELECT id, username, attribute, value, op
FROM radcheck           WHERE username = 'lynnae'           ORDER BY
id
rlm_sql_mysql: query:  SELECT id, username, attribute, value, op
    FROM radcheck           WHERE username = 'lynnae'           ORDER
BY id
[sql] User found in radcheck table
[sql]   expand: SELECT id, username, attribute, value, op
FROM radreply           WHERE username = '%{SQL-User-Name}'
ORDER BY id -> SELECT id, username, attribute, value, op
FROM radreply           WHERE username = 'lynnae'           ORDER BY
id
rlm_sql_mysql: query:  SELECT id, username, attribute, value, op
    FROM radreply           WHERE username = 'lynnae'           ORDER
BY id
[sql]   expand: SELECT groupname           FROM radusergroup
WHERE username = '%{SQL-User-Name}'           ORDER BY priority ->
SELECT groupname           FROM radusergroup           WHERE username
= 'lynnae'           ORDER BY priority
rlm_sql_mysql: query:  SELECT groupname           FROM radusergroup
       WHERE username = 'lynnae'           ORDER BY priority
[sql]   expand: SELECT id, groupname, attribute,           Value, op
        FROM radgroupcheck           WHERE groupname = '%{Sql-Group}'
         ORDER BY id -> SELECT id, groupname, attribute,
Value, op           FROM radgroupcheck           WHERE groupname =
'sandruid-ap-wifi'           ORDER BY id
rlm_sql_mysql: query:  SELECT id, groupname, attribute,
Value, op           FROM radgroupcheck           WHERE groupname =
'sandruid-ap-wifi'           ORDER BY id
[sql] User found in group sandruid-ap-wifi
[sql]   expand: SELECT id, groupname, attribute,           value, op
        FROM radgroupreply           WHERE groupname = '%{Sql-Group}'
         ORDER BY id -> SELECT id, groupname, attribute,
value, op           FROM radgroupreply           WHERE groupname =
'sandruid-ap-wifi'           ORDER BY id
rlm_sql_mysql: query:  SELECT id, groupname, attribute,
value, op           FROM radgroupreply           WHERE groupname =
'sandruid-ap-wifi'           ORDER BY id
rlm_sql (sql): Released sql socket id: 3
++[sql] returns ok
++[expiration] returns noop
++[logintime] returns noop
[pap] WARNING: Auth-Type already set.  Not setting to PAP
++[pap] returns noop
Found Auth-Type = EAP
# Executing group from file /etc/freeradius/sites-enabled/default
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP NAK
[eap] EAP-NAK asked for EAP-Type/peap
[eap] processing type tls
[tls] Initiate
[tls] Start returned 1
++[eap] returns handled
Sending Access-Challenge of id 119 to 192.168.2.254 port 2060
        EAP-Message = 0x010200061920
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x9157e73c9055fe6f0d908f26ca869d55
Finished request 158.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 192.168.2.254 port 2060,
id=120, length=356
        User-Name = "lynnae"
        NAS-IP-Address = 192.168.2.254
        NAS-Port = 0
        Called-Station-Id = "30-46-9A-0E-B4-DF:druid"
        Calling-Station-Id = "7C-61-93-9E-3A-D9"
        Framed-MTU = 1400
        NAS-Port-Type = Wireless-802.11
        Connect-Info = "CONNECT 0Mbps 802.11"
        EAP-Message =
0x020200c81980000000be16030100b9010000b503014eb96cde36b927c58e37146cce91cc535a6cceef3b8b365f9f7b526d985674c6000048c014c00a00390038c00fc0050035c012c00800160013c00dc003000ac013c00900330032c00ec004002fc011c007c00cc002000500040015001200090014001100080006000300ff01000044000b000403000102000a00340032000100020003000400050006000700080009000a000b000c000d000e000f001000110012001300140015001600170018001900230000
        State = 0x9157e73c9055fe6f0d908f26ca869d55
        Message-Authenticator = 0x58c13369bc0531e540918c6bcb3ec054
# Executing section authorize from file /etc/freeradius/sites-enabled/default
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
++[digest] returns noop
[suffix] No '@' in User-Name = "lynnae", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 2 length 200
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
# Executing group from file /etc/freeradius/sites-enabled/default
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/peap
[eap] processing type peap
[peap] processing EAP-TLS
  TLS Length 190
[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 00b9], 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 02ac], 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] returns handled
Sending Access-Challenge of id 120 to 192.168.2.254 port 2060
        EAP-Message =
0x0103040019c00000050216030100310200002d03014eb96cd031034c50878f40ccde3ec71c2bf95397b94f9fc063d800c4c8543e33000039000005ff0100010016030102ac0b0002a80002a50002a23082029e30820186020900ba602d424ee828d3300d06092a864886f70d01010505003011310f300d060355040313067562756e7475301e170d3131303930363232333030395a170d3231303930333232333030395a3011310f300d060355040313067562756e747530820122300d06092a864886f70d01010105000382010f003082010a0282010100d8caabd35a6bf19d2a5b06c9df870fa04b710184efaa79762f6d2ece6126e7e0a79cbe5e2b
        EAP-Message =
0x8ada5c5e816ecea3840944040ee02305a09715f224801793c8d9265d0a1be4fdc666d1913dddb400341390ff579a75fac7860a458fd9d8445a9be140fe8143d8965779fb012ab699b1ab3c7513a40a2c2781dd061171c3850832a1fd01ec9bce0cdbbe94b25da3c27c10d79da9b316d2f8a63534b2369453b07cf5a14eada2eb01b7a00f479e618feedd4b2ab2dfe526fa45e8d0d797f6ac98e45df382f560308018a1c71bd9bb983047852db765a85cff42de810a094eebc958f307e2ef7995f69ff92ada392bef1e7da1e44126b0de749b16c4c645a49cc494730203010001300d06092a864886f70d010105050003820101008d044ec666f3055f91
        EAP-Message =
0x2f64a62addb6bafde8746bcaf0d398f287e6a5ef2ab0e1b3501a9d96924aa46c3d7ddfcacad68497a1b9209af095df62462d02192aa1b11e87520837fa12bfe836f405b71424a973a9ed85c70f0cd769d6f177b63af672cbf4e82101a598579a1b9824f038a74c93e3e39f1ce93b84f1195e9b7165c89052370847e9274836535a3818a6c60d064c8dd6f4b3c78e35ab5d707a81d6e5e80763da0be8c3653a46444a3d7435b88570d62165157fb679769dcd740fc1f36f4c08187cc3eb077238bf12bab3dbfbba681a180f29e7ab2e419cb5881c2f8caeaf71984eb6a068cf5bb143f2ed407ecc845e8e0a6e04fc5e86164e84a3bfdf54160301020d0c
        EAP-Message =
0x0002090080de63877f5ef98ff1ae9d37718a63c89acf13780489524343e6498e734475060fffc46408e77f4021506a063624393308ff58ddf742be1ff813f9f6e1f08261374e51a8e829a6845b8f6253a74dad0c471a3a3445bf0f408db087aa6e88d96490fe375677d9c356f4e2cef235a61b37efa4ca5f2473c1d5c75515a4a0987f3e9b0001020080c3cbfcfa065b6a956d98a8196f32e524fef9bcd90fbe3830f0b02663705fa45bb6eb6632c8258cca123163ad2b5746c4e597ca25685d3f9c56ee64edf871ec56b7d7e6b94b7d67adf6dd8f3bbcccad25a05e8c41406027e1e6459df0387ee4f55d8ed9c61fa56e344dd1224577bfd65a832e83
        EAP-Message = 0x5c20a25f6b1f80f4cbe3d650
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x9157e73c9354fe6f0d908f26ca869d55
Finished request 159.
Going to the next request
Waking up in 4.8 seconds.
rad_recv: Access-Request packet from host 192.168.2.254 port 2060,
id=121, length=162
        User-Name = "lynnae"
        NAS-IP-Address = 192.168.2.254
        NAS-Port = 0
        Called-Station-Id = "30-46-9A-0E-B4-DF:druid"
        Calling-Station-Id = "7C-61-93-9E-3A-D9"
        Framed-MTU = 1400
        NAS-Port-Type = Wireless-802.11
        Connect-Info = "CONNECT 0Mbps 802.11"
        EAP-Message = 0x020300061900
        State = 0x9157e73c9354fe6f0d908f26ca869d55
        Message-Authenticator = 0x7fc90e410524d7826b376a1391760fa9
# Executing section authorize from file /etc/freeradius/sites-enabled/default
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
++[digest] returns noop
[suffix] No '@' in User-Name = "lynnae", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 3 length 6
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
# Executing group from file /etc/freeradius/sites-enabled/default
+- entering 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] returns handled
Sending Access-Challenge of id 121 to 192.168.2.254 port 2060
        EAP-Message =
0x01040112190057010011f1609cfe2fda9cb118e3fcbfb7c4d390cab430a2ced912018992b28ad8c010d4f5404304128996c2ca020da6d662b74f4a1bd67224754c6c01d03b934f906d98608d3bbef927db99d9732cf3e1e4c4a9f2b98460e26ec7271f7931727575efa3332866f4bc1eafabef8fb4e5a44ae23559787695e88c743728df1e2451bcba22c15f78206758ff9856a69f60aec28a219aacba2a870c717b9facedf6c61786176fb6f27e8f482bdff8de46e496b7ba94761441791053429639438efa89e3b32a4d73a321729114b83d3a8ea2213aaee4641b8b50d4608b82f0c349c3f629af1badc84b8f777b95b831161fa68c653486a74cac
        EAP-Message = 0x30ee27a67e3b9b7cc910134516030100040e000000
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x9157e73c9253fe6f0d908f26ca869d55
Finished request 160.
Going to the next request
Waking up in 4.8 seconds.
rad_recv: Access-Request packet from host 192.168.2.254 port 2060,
id=122, length=364
        User-Name = "lynnae"
        NAS-IP-Address = 192.168.2.254
        NAS-Port = 0
        Called-Station-Id = "30-46-9A-0E-B4-DF:druid"
        Calling-Station-Id = "7C-61-93-9E-3A-D9"
        Framed-MTU = 1400
        NAS-Port-Type = Wireless-802.11
        Connect-Info = "CONNECT 0Mbps 802.11"
        EAP-Message =
0x020400d01980000000c6160301008610000082008018689ae4a8f52df5785b79e717bc67f68621f527174b6b5393d1dc4e2487e1cbb18ec0ec67288a81385e234080d150b98cc81c52017495484a046b6cded6bfbc7da09cd4616c1dea539343470fb24dde135acada9517638269f02b7d4b06205934d49449e7357a30e397a648af3d2f0a8bac7e530b544ff1e9df8e7e3aa357a714030100010116030100305ef69b7e3eba1c4cfdfbd73c39ea32c801e076a3f79c753950ab03e82d937937ec91ec8edda3823d2fc0487854fd994f
        State = 0x9157e73c9253fe6f0d908f26ca869d55
        Message-Authenticator = 0x5f0a331b39ab99f4c09a28139714ec92
# Executing section authorize from file /etc/freeradius/sites-enabled/default
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
++[digest] returns noop
[suffix] No '@' in User-Name = "lynnae", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 4 length 208
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
# Executing group from file /etc/freeradius/sites-enabled/default
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/peap
[eap] 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] returns handled
Sending Access-Challenge of id 122 to 192.168.2.254 port 2060
        EAP-Message =
0x010500411900140301000101160301003068692cc43c639c3be14d995f0aa394ff34f50e4bd6ce5518ae5d56436b6ad7e3394992cc8b975b61cefc5d27a9e148e8
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x9157e73c9552fe6f0d908f26ca869d55
Finished request 161.
Going to the next request
Waking up in 4.7 seconds.
rad_recv: Access-Request packet from host 192.168.2.254 port 2060,
id=123, length=162
        User-Name = "lynnae"
        NAS-IP-Address = 192.168.2.254
        NAS-Port = 0
        Called-Station-Id = "30-46-9A-0E-B4-DF:druid"
        Calling-Station-Id = "7C-61-93-9E-3A-D9"
        Framed-MTU = 1400
        NAS-Port-Type = Wireless-802.11
        Connect-Info = "CONNECT 0Mbps 802.11"
        EAP-Message = 0x020500061900
        State = 0x9157e73c9552fe6f0d908f26ca869d55
        Message-Authenticator = 0xaef5497d9e086a476ff8842b93bf4ed8
# Executing section authorize from file /etc/freeradius/sites-enabled/default
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
++[digest] returns noop
[suffix] No '@' in User-Name = "lynnae", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 5 length 6
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
# Executing group from file /etc/freeradius/sites-enabled/default
+- entering 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] returns handled
Sending Access-Challenge of id 123 to 192.168.2.254 port 2060
        EAP-Message =
0x0106002b190017030100207a68818b0219bcaf564d36a844a8c1ede5fe9524fd56adf41092e879f17ae0b3
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x9157e73c9451fe6f0d908f26ca869d55
Finished request 162.
Going to the next request
Waking up in 4.7 seconds.
rad_recv: Access-Request packet from host 192.168.2.254 port 2060,
id=124, length=236
        User-Name = "lynnae"
        NAS-IP-Address = 192.168.2.254
        NAS-Port = 0
        Called-Station-Id = "30-46-9A-0E-B4-DF:druid"
        Calling-Station-Id = "7C-61-93-9E-3A-D9"
        Framed-MTU = 1400
        NAS-Port-Type = Wireless-802.11
        Connect-Info = "CONNECT 0Mbps 802.11"
        EAP-Message =
0x02060050190017030100203b93320a17f41554a43fba3feca2938482da372060063c1e79e814e8bb7f52f617030100205ec652417c1a7fd7b5f04adda23f3c7ab0c964a6d124c19883efb97b15b4214e
        State = 0x9157e73c9451fe6f0d908f26ca869d55
        Message-Authenticator = 0x7f4879d7969ab3029d282075490d5058
# Executing section authorize from file /etc/freeradius/sites-enabled/default
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
++[digest] returns noop
[suffix] No '@' in User-Name = "lynnae", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 6 length 80
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
# Executing group from file /etc/freeradius/sites-enabled/default
+- entering 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 - lynnae
[peap] Got inner identity 'lynnae'
[peap] Setting default EAP type for tunneled EAP session.
[peap] Got tunneled request
        EAP-Message = 0x0206000b016c796e6e6165
server  {
  PEAP: Setting User-Name to lynnae
Sending tunneled request
        EAP-Message = 0x0206000b016c796e6e6165
        FreeRADIUS-Proxied-To = 127.0.0.1
        User-Name = "lynnae"
server inner-tunnel {
# Executing section authorize from file
/etc/freeradius/sites-enabled/inner-tunnel
+- entering group authorize {...}
[sql]   expand: %{User-Name} -> lynnae
[sql] sql_set_user escaped user --> 'lynnae'
rlm_sql (sql): Reserving sql socket id: 2
[sql]   expand: SELECT id, username, attribute, value, op
FROM radcheck           WHERE username = '%{SQL-User-Name}'
ORDER BY id -> SELECT id, username, attribute, value, op
FROM radcheck           WHERE username = 'lynnae'           ORDER BY
id
rlm_sql_mysql: query:  SELECT id, username, attribute, value, op
    FROM radcheck           WHERE username = 'lynnae'           ORDER
BY id
[sql] User found in radcheck table
[sql]   expand: SELECT id, username, attribute, value, op
FROM radreply           WHERE username = '%{SQL-User-Name}'
ORDER BY id -> SELECT id, username, attribute, value, op
FROM radreply           WHERE username = 'lynnae'           ORDER BY
id
rlm_sql_mysql: query:  SELECT id, username, attribute, value, op
    FROM radreply           WHERE username = 'lynnae'           ORDER
BY id
[sql]   expand: SELECT groupname           FROM radusergroup
WHERE username = '%{SQL-User-Name}'           ORDER BY priority ->
SELECT groupname           FROM radusergroup           WHERE username
= 'lynnae'           ORDER BY priority
rlm_sql_mysql: query:  SELECT groupname           FROM radusergroup
       WHERE username = 'lynnae'           ORDER BY priority
[sql]   expand: SELECT id, groupname, attribute,           Value, op
        FROM radgroupcheck           WHERE groupname = '%{Sql-Group}'
         ORDER BY id -> SELECT id, groupname, attribute,
Value, op           FROM radgroupcheck           WHERE groupname =
'sandruid-ap-wifi'           ORDER BY id
rlm_sql_mysql: query:  SELECT id, groupname, attribute,
Value, op           FROM radgroupcheck           WHERE groupname =
'sandruid-ap-wifi'           ORDER BY id
[sql] User found in group sandruid-ap-wifi
[sql]   expand: SELECT id, groupname, attribute,           value, op
        FROM radgroupreply           WHERE groupname = '%{Sql-Group}'
         ORDER BY id -> SELECT id, groupname, attribute,
value, op           FROM radgroupreply           WHERE groupname =
'sandruid-ap-wifi'           ORDER BY id
rlm_sql_mysql: query:  SELECT id, groupname, attribute,
value, op           FROM radgroupreply           WHERE groupname =
'sandruid-ap-wifi'           ORDER BY id
rlm_sql (sql): Released sql socket id: 2
++[sql] returns ok
++[chap] returns noop
++[mschap] returns noop
[suffix] No '@' in User-Name = "lynnae", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
++[control] returns noop
[eap] EAP packet type response id 6 length 11
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
[sql]   expand: %{User-Name} -> lynnae
[sql] sql_set_user escaped user --> 'lynnae'
rlm_sql (sql): Reserving sql socket id: 1
[sql]   expand: SELECT id, username, attribute, value, op
FROM radcheck           WHERE username = '%{SQL-User-Name}'
ORDER BY id -> SELECT id, username, attribute, value, op
FROM radcheck           WHERE username = 'lynnae'           ORDER BY
id
rlm_sql_mysql: query:  SELECT id, username, attribute, value, op
    FROM radcheck           WHERE username = 'lynnae'           ORDER
BY id
[sql] User found in radcheck table
[sql]   expand: SELECT id, username, attribute, value, op
FROM radreply           WHERE username = '%{SQL-User-Name}'
ORDER BY id -> SELECT id, username, attribute, value, op
FROM radreply           WHERE username = 'lynnae'           ORDER BY
id
rlm_sql_mysql: query:  SELECT id, username, attribute, value, op
    FROM radreply           WHERE username = 'lynnae'           ORDER
BY id
[sql]   expand: SELECT groupname           FROM radusergroup
WHERE username = '%{SQL-User-Name}'           ORDER BY priority ->
SELECT groupname           FROM radusergroup           WHERE username
= 'lynnae'           ORDER BY priority
rlm_sql_mysql: query:  SELECT groupname           FROM radusergroup
       WHERE username = 'lynnae'           ORDER BY priority
[sql]   expand: SELECT id, groupname, attribute,           Value, op
        FROM radgroupcheck           WHERE groupname = '%{Sql-Group}'
         ORDER BY id -> SELECT id, groupname, attribute,
Value, op           FROM radgroupcheck           WHERE groupname =
'sandruid-ap-wifi'           ORDER BY id
rlm_sql_mysql: query:  SELECT id, groupname, attribute,
Value, op           FROM radgroupcheck           WHERE groupname =
'sandruid-ap-wifi'           ORDER BY id
[sql] User found in group sandruid-ap-wifi
[sql]   expand: SELECT id, groupname, attribute,           value, op
        FROM radgroupreply           WHERE groupname = '%{Sql-Group}'
         ORDER BY id -> SELECT id, groupname, attribute,
value, op           FROM radgroupreply           WHERE groupname =
'sandruid-ap-wifi'           ORDER BY id
rlm_sql_mysql: query:  SELECT id, groupname, attribute,
value, op           FROM radgroupreply           WHERE groupname =
'sandruid-ap-wifi'           ORDER BY id
rlm_sql (sql): Released sql socket id: 1
++[sql] returns ok
++[expiration] returns noop
++[logintime] returns noop
[pap] WARNING: Auth-Type already set.  Not setting to PAP
++[pap] returns noop
Found Auth-Type = EAP
# Executing group from file /etc/freeradius/sites-enabled/inner-tunnel
+- entering group authenticate {...}
[eap] EAP Identity
[eap] processing type mschapv2
rlm_eap_mschapv2: Issuing Challenge
++[eap] returns handled
} # server inner-tunnel
[peap] Got tunneled reply code 11
        EAP-Message =
0x010700201a0107001b10a49f4b340cb74751d41eab71dea1c3656c796e6e6165
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0xcb0b5cb7cb0c46c5e8b7890586a66df5
[peap] Got tunneled reply RADIUS code 11
        EAP-Message =
0x010700201a0107001b10a49f4b340cb74751d41eab71dea1c3656c796e6e6165
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0xcb0b5cb7cb0c46c5e8b7890586a66df5
[peap] Got tunneled Access-Challenge
++[eap] returns handled
Sending Access-Challenge of id 124 to 192.168.2.254 port 2060
        EAP-Message =
0x0107004b190017030100404bb93a159a1c6d5bb5237d89e435ce74303486a45960d329c8428887d26c3b7c4b02086ec9719bb16228a893b0bc411d2d0c714900f86713ea810d5abcdff4ec
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x9157e73c9750fe6f0d908f26ca869d55
Finished request 163.
Going to the next request
Waking up in 4.7 seconds.
rad_recv: Access-Request packet from host 192.168.2.254 port 2060,
id=125, length=300
        User-Name = "lynnae"
        NAS-IP-Address = 192.168.2.254
        NAS-Port = 0
        Called-Station-Id = "30-46-9A-0E-B4-DF:druid"
        Calling-Station-Id = "7C-61-93-9E-3A-D9"
        Framed-MTU = 1400
        NAS-Port-Type = Wireless-802.11
        Connect-Info = "CONNECT 0Mbps 802.11"
        EAP-Message =
0x02070090190017030100200ad8c74abf696c3e28f1105016b9135fdbc9774b4de57cbeb2bc8255627527ad1703010060bb7a27cab3edffb2b489d65cc6890be1037a4c145325ebd5b7916ef97bb95f9fe6d7287532542d2b4b3d134a8e0d0dc6e30a406768e6f56c2221dc012fb9b8b336f3a923770fc669b7f1057a0ebbb6d4c433d9a31569b04e3f7141147c50ca9d
        State = 0x9157e73c9750fe6f0d908f26ca869d55
        Message-Authenticator = 0x2b81c4d7dc683889d77dc4b66c5aa4c3
# Executing section authorize from file /etc/freeradius/sites-enabled/default
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
++[digest] returns noop
[suffix] No '@' in User-Name = "lynnae", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 7 length 144
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
# Executing group from file /etc/freeradius/sites-enabled/default
+- entering 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 =
0x020700411a0207003c31831e0af9085ee3ef21b1cf05b6f1023600000000000000005f21df5f4a1fe749346f35f30ee425be58039c49d4f4f0d1006c796e6e6165
server  {
  PEAP: Setting User-Name to lynnae
Sending tunneled request
        EAP-Message =
0x020700411a0207003c31831e0af9085ee3ef21b1cf05b6f1023600000000000000005f21df5f4a1fe749346f35f30ee425be58039c49d4f4f0d1006c796e6e6165
        FreeRADIUS-Proxied-To = 127.0.0.1
        User-Name = "lynnae"
        State = 0xcb0b5cb7cb0c46c5e8b7890586a66df5
server inner-tunnel {
# Executing section authorize from file
/etc/freeradius/sites-enabled/inner-tunnel
+- entering group authorize {...}
[sql]   expand: %{User-Name} -> lynnae
[sql] sql_set_user escaped user --> 'lynnae'
rlm_sql (sql): Reserving sql socket id: 0
[sql]   expand: SELECT id, username, attribute, value, op
FROM radcheck           WHERE username = '%{SQL-User-Name}'
ORDER BY id -> SELECT id, username, attribute, value, op
FROM radcheck           WHERE username = 'lynnae'           ORDER BY
id
rlm_sql_mysql: query:  SELECT id, username, attribute, value, op
    FROM radcheck           WHERE username = 'lynnae'           ORDER
BY id
[sql] User found in radcheck table
[sql]   expand: SELECT id, username, attribute, value, op
FROM radreply           WHERE username = '%{SQL-User-Name}'
ORDER BY id -> SELECT id, username, attribute, value, op
FROM radreply           WHERE username = 'lynnae'           ORDER BY
id
rlm_sql_mysql: query:  SELECT id, username, attribute, value, op
    FROM radreply           WHERE username = 'lynnae'           ORDER
BY id
[sql]   expand: SELECT groupname           FROM radusergroup
WHERE username = '%{SQL-User-Name}'           ORDER BY priority ->
SELECT groupname           FROM radusergroup           WHERE username
= 'lynnae'           ORDER BY priority
rlm_sql_mysql: query:  SELECT groupname           FROM radusergroup
       WHERE username = 'lynnae'           ORDER BY priority
[sql]   expand: SELECT id, groupname, attribute,           Value, op
        FROM radgroupcheck           WHERE groupname = '%{Sql-Group}'
         ORDER BY id -> SELECT id, groupname, attribute,
Value, op           FROM radgroupcheck           WHERE groupname =
'sandruid-ap-wifi'           ORDER BY id
rlm_sql_mysql: query:  SELECT id, groupname, attribute,
Value, op           FROM radgroupcheck           WHERE groupname =
'sandruid-ap-wifi'           ORDER BY id
[sql] User found in group sandruid-ap-wifi
[sql]   expand: SELECT id, groupname, attribute,           value, op
        FROM radgroupreply           WHERE groupname = '%{Sql-Group}'
         ORDER BY id -> SELECT id, groupname, attribute,
value, op           FROM radgroupreply           WHERE groupname =
'sandruid-ap-wifi'           ORDER BY id
rlm_sql_mysql: query:  SELECT id, groupname, attribute,
value, op           FROM radgroupreply           WHERE groupname =
'sandruid-ap-wifi'           ORDER BY id
rlm_sql (sql): Released sql socket id: 0
++[sql] returns ok
++[chap] returns noop
++[mschap] returns noop
[suffix] No '@' in User-Name = "lynnae", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
++[control] returns noop
[eap] EAP packet type response id 7 length 65
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
[sql]   expand: %{User-Name} -> lynnae
[sql] sql_set_user escaped user --> 'lynnae'
rlm_sql (sql): Reserving sql socket id: 4
[sql]   expand: SELECT id, username, attribute, value, op
FROM radcheck           WHERE username = '%{SQL-User-Name}'
ORDER BY id -> SELECT id, username, attribute, value, op
FROM radcheck           WHERE username = 'lynnae'           ORDER BY
id
rlm_sql_mysql: query:  SELECT id, username, attribute, value, op
    FROM radcheck           WHERE username = 'lynnae'           ORDER
BY id
[sql] User found in radcheck table
[sql]   expand: SELECT id, username, attribute, value, op
FROM radreply           WHERE username = '%{SQL-User-Name}'
ORDER BY id -> SELECT id, username, attribute, value, op
FROM radreply           WHERE username = 'lynnae'           ORDER BY
id
rlm_sql_mysql: query:  SELECT id, username, attribute, value, op
    FROM radreply           WHERE username = 'lynnae'           ORDER
BY id
[sql]   expand: SELECT groupname           FROM radusergroup
WHERE username = '%{SQL-User-Name}'           ORDER BY priority ->
SELECT groupname           FROM radusergroup           WHERE username
= 'lynnae'           ORDER BY priority
rlm_sql_mysql: query:  SELECT groupname           FROM radusergroup
       WHERE username = 'lynnae'           ORDER BY priority
[sql]   expand: SELECT id, groupname, attribute,           Value, op
        FROM radgroupcheck           WHERE groupname = '%{Sql-Group}'
         ORDER BY id -> SELECT id, groupname, attribute,
Value, op           FROM radgroupcheck           WHERE groupname =
'sandruid-ap-wifi'           ORDER BY id
rlm_sql_mysql: query:  SELECT id, groupname, attribute,
Value, op           FROM radgroupcheck           WHERE groupname =
'sandruid-ap-wifi'           ORDER BY id
[sql] User found in group sandruid-ap-wifi
[sql]   expand: SELECT id, groupname, attribute,           value, op
        FROM radgroupreply           WHERE groupname = '%{Sql-Group}'
         ORDER BY id -> SELECT id, groupname, attribute,
value, op           FROM radgroupreply           WHERE groupname =
'sandruid-ap-wifi'           ORDER BY id
rlm_sql_mysql: query:  SELECT id, groupname, attribute,
value, op           FROM radgroupreply           WHERE groupname =
'sandruid-ap-wifi'           ORDER BY id
rlm_sql (sql): Released sql socket id: 4
++[sql] returns ok
++[expiration] returns noop
++[logintime] returns noop
[pap] WARNING: Auth-Type already set.  Not setting to PAP
++[pap] returns noop
Found Auth-Type = EAP
# Executing group from file /etc/freeradius/sites-enabled/inner-tunnel
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/mschapv2
[eap] processing type mschapv2
[mschapv2] # Executing group from file
/etc/freeradius/sites-enabled/inner-tunnel
[mschapv2] +- entering group MS-CHAP {...}
[mschap] Creating challenge hash with username: lynnae
[mschap] Told to do MS-CHAPv2 for lynnae with NT-Password
[mschap] adding MS-CHAPv2 MPPE keys
++[mschap] returns ok
MSCHAP Success
++[eap] returns handled
} # server inner-tunnel
[peap] Got tunneled reply code 11
        EAP-Message =
0x010800331a0307002e533d41304337333331334131393842343535453932393139314536373931423133323236343832444536
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0xcb0b5cb7ca0346c5e8b7890586a66df5
[peap] Got tunneled reply RADIUS code 11
        EAP-Message =
0x010800331a0307002e533d41304337333331334131393842343535453932393139314536373931423133323236343832444536
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0xcb0b5cb7ca0346c5e8b7890586a66df5
[peap] Got tunneled Access-Challenge
++[eap] returns handled
Sending Access-Challenge of id 125 to 192.168.2.254 port 2060
        EAP-Message =
0x0108005b19001703010050d4ef871ef051eee9064cbccd470060a8b87bb932e68b1bccbb4e785482d44706047401c585a1bff2b413de10675f0879a882c7eab49a9e6021420798515a86b6038a8492a06e6a9f4aa3d52247dcbdb3
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x9157e73c965ffe6f0d908f26ca869d55
Finished request 164.
Going to the next request
Waking up in 4.7 seconds.
rad_recv: Access-Request packet from host 192.168.2.254 port 2060,
id=126, length=236
        User-Name = "lynnae"
        NAS-IP-Address = 192.168.2.254
        NAS-Port = 0
        Called-Station-Id = "30-46-9A-0E-B4-DF:druid"
        Calling-Station-Id = "7C-61-93-9E-3A-D9"
        Framed-MTU = 1400
        NAS-Port-Type = Wireless-802.11
        Connect-Info = "CONNECT 0Mbps 802.11"
        EAP-Message =
0x0208005019001703010020c7a82ee86578ced416e7b235e6a7dc0e820e535a79e74b51e898a5ee2987a19617030100207ccbea411a1626f94f5346f51111cc82a43507e66fdd3085253b682bd18f3e12
        State = 0x9157e73c965ffe6f0d908f26ca869d55
        Message-Authenticator = 0x99343416c2852adf5b655e9243d67783
# Executing section authorize from file /etc/freeradius/sites-enabled/default
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
++[digest] returns noop
[suffix] No '@' in User-Name = "lynnae", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 8 length 80
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
# Executing group from file /etc/freeradius/sites-enabled/default
+- entering 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 = 0x020800061a03
server  {
  PEAP: Setting User-Name to lynnae
Sending tunneled request
        EAP-Message = 0x020800061a03
        FreeRADIUS-Proxied-To = 127.0.0.1
        User-Name = "lynnae"
        State = 0xcb0b5cb7ca0346c5e8b7890586a66df5
server inner-tunnel {
# Executing section authorize from file
/etc/freeradius/sites-enabled/inner-tunnel
+- entering group authorize {...}
[sql]   expand: %{User-Name} -> lynnae
[sql] sql_set_user escaped user --> 'lynnae'
rlm_sql (sql): Reserving sql socket id: 3
[sql]   expand: SELECT id, username, attribute, value, op
FROM radcheck           WHERE username = '%{SQL-User-Name}'
ORDER BY id -> SELECT id, username, attribute, value, op
FROM radcheck           WHERE username = 'lynnae'           ORDER BY
id
rlm_sql_mysql: query:  SELECT id, username, attribute, value, op
    FROM radcheck           WHERE username = 'lynnae'           ORDER
BY id
[sql] User found in radcheck table
[sql]   expand: SELECT id, username, attribute, value, op
FROM radreply           WHERE username = '%{SQL-User-Name}'
ORDER BY id -> SELECT id, username, attribute, value, op
FROM radreply           WHERE username = 'lynnae'           ORDER BY
id
rlm_sql_mysql: query:  SELECT id, username, attribute, value, op
    FROM radreply           WHERE username = 'lynnae'           ORDER
BY id
[sql]   expand: SELECT groupname           FROM radusergroup
WHERE username = '%{SQL-User-Name}'           ORDER BY priority ->
SELECT groupname           FROM radusergroup           WHERE username
= 'lynnae'           ORDER BY priority
rlm_sql_mysql: query:  SELECT groupname           FROM radusergroup
       WHERE username = 'lynnae'           ORDER BY priority
[sql]   expand: SELECT id, groupname, attribute,           Value, op
        FROM radgroupcheck           WHERE groupname = '%{Sql-Group}'
         ORDER BY id -> SELECT id, groupname, attribute,
Value, op           FROM radgroupcheck           WHERE groupname =
'sandruid-ap-wifi'           ORDER BY id
rlm_sql_mysql: query:  SELECT id, groupname, attribute,
Value, op           FROM radgroupcheck           WHERE groupname =
'sandruid-ap-wifi'           ORDER BY id
[sql] User found in group sandruid-ap-wifi
[sql]   expand: SELECT id, groupname, attribute,           value, op
        FROM radgroupreply           WHERE groupname = '%{Sql-Group}'
         ORDER BY id -> SELECT id, groupname, attribute,
value, op           FROM radgroupreply           WHERE groupname =
'sandruid-ap-wifi'           ORDER BY id
rlm_sql_mysql: query:  SELECT id, groupname, attribute,
value, op           FROM radgroupreply           WHERE groupname =
'sandruid-ap-wifi'           ORDER BY id
rlm_sql (sql): Released sql socket id: 3
++[sql] returns ok
++[chap] returns noop
++[mschap] returns noop
[suffix] No '@' in User-Name = "lynnae", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
++[control] returns noop
[eap] EAP packet type response id 8 length 6
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
[sql]   expand: %{User-Name} -> lynnae
[sql] sql_set_user escaped user --> 'lynnae'
rlm_sql (sql): Reserving sql socket id: 2
[sql]   expand: SELECT id, username, attribute, value, op
FROM radcheck           WHERE username = '%{SQL-User-Name}'
ORDER BY id -> SELECT id, username, attribute, value, op
FROM radcheck           WHERE username = 'lynnae'           ORDER BY
id
rlm_sql_mysql: query:  SELECT id, username, attribute, value, op
    FROM radcheck           WHERE username = 'lynnae'           ORDER
BY id
[sql] User found in radcheck table
[sql]   expand: SELECT id, username, attribute, value, op
FROM radreply           WHERE username = '%{SQL-User-Name}'
ORDER BY id -> SELECT id, username, attribute, value, op
FROM radreply           WHERE username = 'lynnae'           ORDER BY
id
rlm_sql_mysql: query:  SELECT id, username, attribute, value, op
    FROM radreply           WHERE username = 'lynnae'           ORDER
BY id
[sql]   expand: SELECT groupname           FROM radusergroup
WHERE username = '%{SQL-User-Name}'           ORDER BY priority ->
SELECT groupname           FROM radusergroup           WHERE username
= 'lynnae'           ORDER BY priority
rlm_sql_mysql: query:  SELECT groupname           FROM radusergroup
       WHERE username = 'lynnae'           ORDER BY priority
[sql]   expand: SELECT id, groupname, attribute,           Value, op
        FROM radgroupcheck           WHERE groupname = '%{Sql-Group}'
         ORDER BY id -> SELECT id, groupname, attribute,
Value, op           FROM radgroupcheck           WHERE groupname =
'sandruid-ap-wifi'           ORDER BY id
rlm_sql_mysql: query:  SELECT id, groupname, attribute,
Value, op           FROM radgroupcheck           WHERE groupname =
'sandruid-ap-wifi'           ORDER BY id
[sql] User found in group sandruid-ap-wifi
[sql]   expand: SELECT id, groupname, attribute,           value, op
        FROM radgroupreply           WHERE groupname = '%{Sql-Group}'
         ORDER BY id -> SELECT id, groupname, attribute,
value, op           FROM radgroupreply           WHERE groupname =
'sandruid-ap-wifi'           ORDER BY id
rlm_sql_mysql: query:  SELECT id, groupname, attribute,
value, op           FROM radgroupreply           WHERE groupname =
'sandruid-ap-wifi'           ORDER BY id
rlm_sql (sql): Released sql socket id: 2
++[sql] returns ok
++[expiration] returns noop
++[logintime] returns noop
[pap] WARNING: Auth-Type already set.  Not setting to PAP
++[pap] returns noop
Found Auth-Type = EAP
# Executing group from file /etc/freeradius/sites-enabled/inner-tunnel
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/mschapv2
[eap] processing type mschapv2
[eap] Freeing handler
++[eap] returns ok
# Executing section session from file /etc/freeradius/sites-enabled/inner-tunnel
+- entering group session {...}
[sql]   expand: %{User-Name} -> lynnae
[sql] sql_set_user escaped user --> 'lynnae'
[sql]   expand: SELECT COUNT(*)                              #FROM
radacct                              #WHERE username =
'%{SQL-User-Name}'                              #AND acctstoptime IS
NULL -> SELECT COUNT(*)                              #FROM radacct
                         #WHERE username = 'lynnae'
          #AND acctstoptime IS NULL
rlm_sql (sql): Reserving sql socket id: 1
rlm_sql_mysql: query:  SELECT COUNT(*)
#FROM radacct                              #WHERE username = 'lynnae'
                            #AND acctstoptime IS NULL
[sql]   expand: SELECT radacctid, acctsessionid, username,
                   nasipaddress, nasportid, framedipaddress,
                     callingstationid, framedprotocol
              FROM radacct                                WHERE
username = '%{SQL-User-Name}'                                AND
acctstoptime IS NULL -> SELECT radacctid, acctsessionid, username,
                           nasipaddress, nasportid, framedipaddress,
                             callingstationid, framedprotocol
                      FROM radacct
WHERE username = 'lynnae'                                AND
acctstoptime IS NULL
rlm_sql_mysql: query:  SELECT radacctid, acctsessionid, username,
                          nasipaddress, nasportid, framedipaddress,
                            callingstationid, framedprotocol
                     FROM radacct                                WHERE
username = 'lynnae'                                AND acctstoptime IS
NULL
rlm_sql (sql): Released sql socket id: 1
++[sql] returns ok
# Executing section post-auth from file
/etc/freeradius/sites-enabled/inner-tunnel
+- entering group post-auth {...}
[sql]   expand: %{User-Name} -> lynnae
[sql] sql_set_user escaped user --> 'lynnae'
[sql]   expand: %{User-Password} ->
[sql]   ... expanding second conditional
[sql]   expand: %{Chap-Password} ->
[sql]   expand: INSERT INTO radpostauth
(username, pass, reply, authdate)                           VALUES (
                        '%{User-Name}',
'%{%{User-Password}:-%{Chap-Password}}',
'%{reply:Packet-Type}', '%S') -> INSERT INTO radpostauth
            (username, pass, reply, authdate)
 VALUES (                           'lynnae',
 '',                           'Access-Accept', '2011-11-08 10:54:24')
[sql]   expand: /var/log/freeradius/sqltrace.sql ->
/var/log/freeradius/sqltrace.sql
rlm_sql (sql) in sql_postauth: query is INSERT INTO radpostauth
                   (username, pass, reply, authdate)
        VALUES (                           'lynnae',
        '',                           'Access-Accept', '2011-11-08
10:54:24')
rlm_sql (sql): Reserving sql socket id: 0
rlm_sql_mysql: query:  INSERT INTO radpostauth
  (username, pass, reply, authdate)                           VALUES (
                          'lynnae',                           '',
                     'Access-Accept', '2011-11-08 10:54:24')
rlm_sql (sql): Released sql socket id: 0
++[sql] returns ok
} # server inner-tunnel
[peap] Got tunneled reply code 2
        MS-MPPE-Encryption-Policy = 0x00000001
        MS-MPPE-Encryption-Types = 0x00000006
        MS-MPPE-Send-Key = 0x64d23cb7d938395e60b2bc98eb9667b1
        MS-MPPE-Recv-Key = 0x1cf788005312432f10b9b54e6ada00ca
        EAP-Message = 0x03080004
        Message-Authenticator = 0x00000000000000000000000000000000
        User-Name = "lynnae"
[peap] Got tunneled reply RADIUS code 2
        MS-MPPE-Encryption-Policy = 0x00000001
        MS-MPPE-Encryption-Types = 0x00000006
        MS-MPPE-Send-Key = 0x64d23cb7d938395e60b2bc98eb9667b1
        MS-MPPE-Recv-Key = 0x1cf788005312432f10b9b54e6ada00ca
        EAP-Message = 0x03080004
        Message-Authenticator = 0x00000000000000000000000000000000
        User-Name = "lynnae"
[peap] Tunneled authentication was successful.
[peap] SUCCESS
++[eap] returns handled
Sending Access-Challenge of id 126 to 192.168.2.254 port 2060
        EAP-Message =
0x0109002b190017030100203b08dfc30d197b615b6fd93ace4064321d2d342373d79450163e1d77d966c2f1
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x9157e73c995efe6f0d908f26ca869d55
Finished request 165.
Going to the next request
Waking up in 4.7 seconds.
rad_recv: Access-Request packet from host 192.168.2.254 port 2060,
id=127, length=236
        User-Name = "lynnae"
        NAS-IP-Address = 192.168.2.254
        NAS-Port = 0
        Called-Station-Id = "30-46-9A-0E-B4-DF:druid"
        Calling-Station-Id = "7C-61-93-9E-3A-D9"
        Framed-MTU = 1400
        NAS-Port-Type = Wireless-802.11
        Connect-Info = "CONNECT 0Mbps 802.11"
        EAP-Message =
0x0209005019001703010020bed5ff20d6475746ddae396e91ec11a0c3fbfd81efa0edbe1c567395bf43547b170301002007b4740b564efd19a9e3400e8847bf04f4260b75a7e9983f4d5f6d60fe05273b
        State = 0x9157e73c995efe6f0d908f26ca869d55
        Message-Authenticator = 0xc7bf139807bb5c02c88262210dea9c27
# Executing section authorize from file /etc/freeradius/sites-enabled/default
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
++[digest] returns noop
[suffix] No '@' in User-Name = "lynnae", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 9 length 80
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
# Executing group from file /etc/freeradius/sites-enabled/default
+- entering 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
[eap] Freeing handler
++[eap] returns ok
# Executing section post-auth from file /etc/freeradius/sites-enabled/default
+- entering group post-auth {...}
[sql]   expand: %{User-Name} -> lynnae
[sql] sql_set_user escaped user --> 'lynnae'
[sql]   expand: %{User-Password} ->
[sql]   ... expanding second conditional
[sql]   expand: %{Chap-Password} ->
[sql]   expand: INSERT INTO radpostauth
(username, pass, reply, authdate)                           VALUES (
                        '%{User-Name}',
'%{%{User-Password}:-%{Chap-Password}}',
'%{reply:Packet-Type}', '%S') -> INSERT INTO radpostauth
            (username, pass, reply, authdate)
 VALUES (                           'lynnae',
 '',                           'Access-Accept', '2011-11-08 10:54:24')
[sql]   expand: /var/log/freeradius/sqltrace.sql ->
/var/log/freeradius/sqltrace.sql
rlm_sql (sql) in sql_postauth: query is INSERT INTO radpostauth
                   (username, pass, reply, authdate)
        VALUES (                           'lynnae',
        '',                           'Access-Accept', '2011-11-08
10:54:24')
rlm_sql (sql): Reserving sql socket id: 4
rlm_sql_mysql: query:  INSERT INTO radpostauth
  (username, pass, reply, authdate)                           VALUES (
                          'lynnae',                           '',
                     'Access-Accept', '2011-11-08 10:54:24')
rlm_sql (sql): Released sql socket id: 4
++[sql] returns ok
++[exec] returns noop
Sending Access-Accept of id 127 to 192.168.2.254 port 2060