A tale of 2 WiMax NAS

David Peterson davidp at wirelessconnections.net
Wed Oct 20 19:53:26 CEST 2010


OK here is the debug output from the NAS requiring those two entries
commented out.  The CPE are authenticated and the Framed-Filter-Id is sent
back properly but the subscribers never receive service.  

        EAP-Message = 0x03080004
        Message-Authenticator = 0x00000000000000000000000000000000
        User-Name = "{am=1}E16C264A7784B7B86380C1087F7143C2"
        WiMAX-IP-Technology = CMIP4
        WiMAX-FA-RK-Key = 0x557aa1e75f677ac869ea7cddad1d4d8eb4bc1c15
        WiMAX-MSK = 0x
        WiMAX-MSK =
0x9ff71c6efbd6db6fa56de244f7863855f2570a0f9e50fb08175e5570da3741de219a8f6a79
353d50a443488d7ad3631e896684d3c4e360c2e8dc9d7b2faae2c0
        WiMAX-FA-RK-SPI = 4080449119
Finished request 546.
Going to the next request
Waking up in 3.1 seconds.
Cleaning up request 539 ID 126 with timestamp +8431
Cleaning up request 540 ID 127 with timestamp +8431
Cleaning up request 541 ID 128 with timestamp +8431
Cleaning up request 542 ID 129 with timestamp +8431
Cleaning up request 543 ID 130 with timestamp +8431
Waking up in 1.3 seconds.
Cleaning up request 544 ID 131 with timestamp +8433
Waking up in 0.1 seconds.
Cleaning up request 545 ID 132 with timestamp +8433
Cleaning up request 546 ID 133 with timestamp +8433
Ready to process requests.
rad_recv: Access-Request packet from host 172.16.4.2 port 1812, id=134,
length=252
        User-Name = "{am=1}172E3FAD27897FBB29D016059C621B03 at WiMax.com"
        EAP-Message =
0x02010035017b616d3d317d3137324533464144323738393746424232394430313630353943
3632314230334057694d61782e636f6d
        Message-Authenticator = 0xbcad3e78aa2580a803ec6771574f8b1d
        NAS-Identifier = "Freeradius"
        NAS-IP-Address = 172.16.4.2
        Calling-Station-Id = "00-A0-0A-13-13-72"
        WiMAX-BS-Id = 0x000002010203
        NAS-Port-Type = 27
        Framed-MTU = 2000
        Service-Type = Framed-User
        WiMAX-GMT-Timezone-offset = 0
        WiMAX-Release = "1.0"
        WiMAX-Accounting-Capabilities = IP-Session-Based
        WiMAX-Hotlining-Capabilities = Hotline-Profile-Id
        WiMAX-Attr-1793 = 0x0000028a
+- entering group authorize {...}
++[preprocess] returns ok
++[mschap] returns noop
++[wimax] returns ok
[suffix] Looking up realm "WiMax.com" for User-Name =
"{am=1}172E3FAD27897FBB29D016059C621B03 at WiMax.com"
[suffix] Found realm "WiMax.com"
[suffix] Adding Stripped-User-Name =
"{am=1}172E3FAD27897FBB29D016059C621B03"
[suffix] Adding Realm = "WiMax.com"
[suffix] Authentication realm is LOCAL.
++[suffix] returns ok
[eap] EAP packet type response id 1 length 53
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
++[files] returns noop
[sql]   expand: %{User-Name} ->
{am=1}172E3FAD27897FBB29D016059C621B03 at WiMax.com
[sql] sql_set_user escaped user -->
'{am=1}172E3FAD27897FBB29D016059C621B03 at WiMax.com'
rlm_sql (sql): Reserving sql socket id: 2
[sql]   expand: SELECT id, username, attribute, value, op          FROM
radcheck          WHERE username = BINARY '%{SQL-User-Name}'          ORDER
BY id -> SELECT id, username, attribute, value, op          FROM radcheck
WHERE username = BINARY
'=7Bam=3D1=7D172E3FAD27897FBB29D016059C621B03 at WiMax.com'          ORDER BY
id
[sql]   expand: SELECT groupname          FROM radusergroup         WHERE
username = BINARY '%{SQL-User-Name}'          ORDER BY priority -> SELECT
groupname          FROM radusergroup         WHERE username = BINARY
'=7Bam=3D1=7D172E3FAD27897FBB29D016059C621B03 at WiMax.com'          ORDER BY
priority
rlm_sql (sql): Released sql socket id: 2
[sql] User {am=1}172E3FAD27897FBB29D016059C621B03 at WiMax.com not found
++[sql] returns notfound
++[expiration] returns noop
++[logintime] returns noop
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] EAP Identity
[eap] processing type md5
rlm_eap_md5: Issuing Challenge
++[eap] returns handled
Sending Access-Challenge of id 134 to 172.16.4.2 port 1812
        EAP-Message = 0x0102001604106f87eaef5fb2c869f5ea9cc7bbd6f167
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x478ccb12478ecf59ab6dcf8f64d052f7
Finished request 547.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 172.16.4.2 port 1812, id=135,
length=223
        User-Name = "{am=1}172E3FAD27897FBB29D016059C621B03 at WiMax.com"
        EAP-Message = 0x020200060315
        Message-Authenticator = 0x5c7b646a4e15bcaa02ab2fba84de80bc
        NAS-Identifier = "Freeradius"
        NAS-IP-Address = 172.16.4.2
        Calling-Station-Id = "00-A0-0A-13-13-72"
        WiMAX-BS-Id = 0x000002010203
        NAS-Port-Type = 27
        Framed-MTU = 2000
        Service-Type = Framed-User
        WiMAX-GMT-Timezone-offset = 0
        WiMAX-Release = "1.0"
        WiMAX-Accounting-Capabilities = IP-Session-Based
        WiMAX-Hotlining-Capabilities = Hotline-Profile-Id
        WiMAX-Attr-1793 = 0x0000028a
        State = 0x478ccb12478ecf59ab6dcf8f64d052f7
+- entering group authorize {...}
++[preprocess] returns ok
++[mschap] returns noop
++[wimax] returns ok
[suffix] Looking up realm "WiMax.com" for User-Name =
"{am=1}172E3FAD27897FBB29D016059C621B03 at WiMax.com"
[suffix] Found realm "WiMax.com"
[suffix] Adding Stripped-User-Name =
"{am=1}172E3FAD27897FBB29D016059C621B03"
[suffix] Adding Realm = "WiMax.com"
[suffix] Authentication realm is LOCAL.
++[suffix] returns ok
[eap] EAP packet type response id 2 length 6
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
++[files] returns noop
[sql]   expand: %{User-Name} ->
{am=1}172E3FAD27897FBB29D016059C621B03 at WiMax.com
[sql] sql_set_user escaped user -->
'{am=1}172E3FAD27897FBB29D016059C621B03 at WiMax.com'
rlm_sql (sql): Reserving sql socket id: 1
[sql]   expand: SELECT id, username, attribute, value, op          FROM
radcheck          WHERE username = BINARY '%{SQL-User-Name}'          ORDER
BY id -> SELECT id, username, attribute, value, op          FROM radcheck
WHERE username = BINARY
'=7Bam=3D1=7D172E3FAD27897FBB29D016059C621B03 at WiMax.com'          ORDER BY
id
[sql]   expand: SELECT groupname          FROM radusergroup         WHERE
username = BINARY '%{SQL-User-Name}'          ORDER BY priority -> SELECT
groupname          FROM radusergroup         WHERE username = BINARY
'=7Bam=3D1=7D172E3FAD27897FBB29D016059C621B03 at WiMax.com'          ORDER BY
priority
rlm_sql (sql): Released sql socket id: 1
[sql] User {am=1}172E3FAD27897FBB29D016059C621B03 at WiMax.com not found
++[sql] returns notfound
++[expiration] returns noop
++[logintime] returns noop
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP NAK
[eap] EAP-NAK asked for EAP-Type/ttls
[eap] processing type tls
[tls] Initiate
[tls] Start returned 1
++[eap] returns handled
Sending Access-Challenge of id 135 to 172.16.4.2 port 1812
        EAP-Message = 0x010300061520
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x478ccb12468fde59ab6dcf8f64d052f7
Finished request 548.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 172.16.4.2 port 1812, id=136,
length=305
        User-Name = "{am=1}172E3FAD27897FBB29D016059C621B03 at WiMax.com"
        EAP-Message =
0x0203005815800000004e16030100490100004503014ba56db22185a9f76d29a4d2adb55f14
98e0cf24850e4500ca78d654b408fc0000001e00390038003500160013000a00330032002f00
15001200090014001100080100
        Message-Authenticator = 0x88f33e618e713504847509a6e0d3150b
        NAS-Identifier = "Freeradius"
        NAS-IP-Address = 172.16.4.2
        Calling-Station-Id = "00-A0-0A-13-13-72"
        WiMAX-BS-Id = 0x000002010203
        NAS-Port-Type = 27
        Framed-MTU = 2000
        Service-Type = Framed-User
        WiMAX-GMT-Timezone-offset = 0
        WiMAX-Release = "1.0"
        WiMAX-Accounting-Capabilities = IP-Session-Based
        WiMAX-Hotlining-Capabilities = Hotline-Profile-Id
        WiMAX-Attr-1793 = 0x0000028a
        State = 0x478ccb12468fde59ab6dcf8f64d052f7
+- entering group authorize {...}
++[preprocess] returns ok
++[mschap] returns noop
++[wimax] returns ok
[suffix] Looking up realm "WiMax.com" for User-Name =
"{am=1}172E3FAD27897FBB29D016059C621B03 at WiMax.com"
[suffix] Found realm "WiMax.com"
[suffix] Adding Stripped-User-Name =
"{am=1}172E3FAD27897FBB29D016059C621B03"
[suffix] Adding Realm = "WiMax.com"
[suffix] Authentication realm is LOCAL.
++[suffix] returns ok
[eap] EAP packet type response id 3 length 88
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/ttls
[eap] processing type ttls
[ttls] Authenticate
[ttls] processing EAP-TLS
  TLS Length 78
[ttls] Length Included
[ttls] eaptls_verify returned 11
[ttls]     (other): before/accept initialization
[ttls]     TLS_accept: before/accept initialization
[ttls] <<< TLS 1.0 Handshake [length 0049], ClientHello
[ttls]     TLS_accept: SSLv3 read client hello A
[ttls] >>> TLS 1.0 Handshake [length 002a], ServerHello
[ttls]     TLS_accept: SSLv3 write server hello A
[ttls] >>> TLS 1.0 Handshake [length 085e], Certificate
[ttls]     TLS_accept: SSLv3 write certificate A
[ttls] >>> TLS 1.0 Handshake [length 020d], ServerKeyExchange
[ttls]     TLS_accept: SSLv3 write key exchange A
[ttls] >>> TLS 1.0 Handshake [length 0004], ServerHelloDone
[ttls]     TLS_accept: SSLv3 write server done A
[ttls]     TLS_accept: SSLv3 flush data
[ttls]     TLS_accept: Need to read more data: SSLv3 read client certificate
A
In SSL Handshake Phase
In SSL Accept mode
[ttls] eaptls_process returned 13
++[eap] returns handled
Sending Access-Challenge of id 136 to 172.16.4.2 port 1812
        EAP-Message =
0x0104040015c000000aad160301002a0200002603014cbf28a1c3eb9d327ad351652f04cabf
9821f3c17dc245ad28145764c786e7f900003900160301085e0b00085a0008570003a6308203
a23082028aa003020102020101300d06092a864886f70d0101040500308193310b3009060355
040613024652310f300d060355040813065261646975733112301006035504071309536f6d65
776865726531153013060355040a130c4578616d706c6520496e632e3120301e06092a864886
f70d010901161161646d696e406578616d706c652e636f6d312630240603550403131d457861
6d706c6520436572746966696361746520417574686f72697479
        EAP-Message =
0x301e170d3130303632313139303034345a170d3131303632313139303034345a307c310b30
09060355040613024652310f300d0603550408130652616469757331153013060355040a130c
4578616d706c6520496e632e312330210603550403131a4578616d706c652053657276657220
43657274696669636174653120301e06092a864886f70d010901161161646d696e406578616d
706c652e636f6d30820122300d06092a864886f70d01010105000382010f003082010a028201
0100a22c435dd3157a79c141fdc1a3ee89f7661a09187b958a5816beff7591e4b6aa37f7f256
cb182fffd65c4000a1498020aea03360223fad98df86a01d7b3c
        EAP-Message =
0xea1055ffdadbf60a2ea1b7af5a728cb75ec7e06ee90c39a9d6b1bdef454343d51c4f489be8
d3e17f545a9e8b7ac612dba36cf14c1a7709651d1bf04a057c4188fecee0dd6d80b9d5cca836
5e3e0aeccf0deef1f7516cce7d30fbe1271f8fcb25be192fbaf623340024debf13487225fead
75a4e557f21cb9707d519d2ad8de57eeda2c8b6afc7fc2b0e1a890fec212c80455a83a8b41bb
b35fc6420b167139c6033757b38124c971da04bd1c6da985c65077f55bee5b37c65e1f8cefa3
25c1672bff0203010001a317301530130603551d25040c300a06082b06010505070301300d06
092a864886f70d01010405000382010100c21ae0152cdbce17a1
        EAP-Message =
0x55233bf585be76ec2a3265e3e6ee7132890dc68d37c1864b08ba53f34c358953c528f8ab14
4716d17ebcd4f1b86f53522ce118b1a8932dfe4e3234137e94aecc3737c66d07405c9c369d2a
04f4d11c96685996d95313a35fde3b433d15eb93c915814fca156b6c5fcff010968ef7613142
d4cd95da673bdc1217739a88f8d43bb6ca26bee37a64f8ce1b50ec1b8e7c11c5291c88b5ebea
2e766bc31139fc03482232660ea54c22273996250eab67b9198b4ad378c5e1635162ffc5e382
bf5d60dd149e6c1b9f05eb5e94824b103f77e6e5875f6f8beeb48302defec698296f20c9ba78
9341834806deb515116aedc41d90bfebfaf0bea20004ab308204
        EAP-Message = 0xa73082038fa0030201020209
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x478ccb124588de59ab6dcf8f64d052f7
Finished request 549.
Going to the next request
Waking up in 4.8 seconds.
rad_recv: Access-Request packet from host 172.16.4.2 port 1812, id=137,
length=223
        User-Name = "{am=1}172E3FAD27897FBB29D016059C621B03 at WiMax.com"
        EAP-Message = 0x020400061500
        Message-Authenticator = 0x0f160700bd7a7dde77c1dbac4e9ca0bd
        NAS-Identifier = "Freeradius"
        NAS-IP-Address = 172.16.4.2
        Calling-Station-Id = "00-A0-0A-13-13-72"
        WiMAX-BS-Id = 0x000002010203
        NAS-Port-Type = 27
        Framed-MTU = 2000
        Service-Type = Framed-User
        WiMAX-GMT-Timezone-offset = 0
        WiMAX-Release = "1.0"
        WiMAX-Accounting-Capabilities = IP-Session-Based
        WiMAX-Hotlining-Capabilities = Hotline-Profile-Id
        WiMAX-Attr-1793 = 0x0000028a
        State = 0x478ccb124588de59ab6dcf8f64d052f7
+- entering group authorize {...}
++[preprocess] returns ok
++[mschap] returns noop
++[wimax] returns ok
[suffix] Looking up realm "WiMax.com" for User-Name =
"{am=1}172E3FAD27897FBB29D016059C621B03 at WiMax.com"
[suffix] Found realm "WiMax.com"
[suffix] Adding Stripped-User-Name =
"{am=1}172E3FAD27897FBB29D016059C621B03"
[suffix] Adding Realm = "WiMax.com"
[suffix] Authentication realm is LOCAL.
++[suffix] returns ok
[eap] EAP packet type response id 4 length 6
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/ttls
[eap] processing type ttls
[ttls] Authenticate
[ttls] processing EAP-TLS
[ttls] Received TLS ACK
[ttls] ACK handshake fragment handler
[ttls] eaptls_verify returned 1
[ttls] eaptls_process returned 13
++[eap] returns handled
Sending Access-Challenge of id 137 to 172.16.4.2 port 1812
        EAP-Message =
0x0105040015c000000aad00b7ca1f4a75b65c48300d06092a864886f70d0101050500308193
310b3009060355040613024652310f300d060355040813065261646975733112301006035504
071309536f6d65776865726531153013060355040a130c4578616d706c6520496e632e312030
1e06092a864886f70d010901161161646d696e406578616d706c652e636f6d31263024060355
0403131d4578616d706c6520436572746966696361746520417574686f72697479301e170d31
30303632313139303034345a170d3131303632313139303034345a308193310b300906035504
0613024652310f300d0603550408130652616469757331123010
        EAP-Message =
0x06035504071309536f6d65776865726531153013060355040a130c4578616d706c6520496e
632e3120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d3126
30240603550403131d4578616d706c6520436572746966696361746520417574686f72697479
30820122300d06092a864886f70d01010105000382010f003082010a0282010100e3290705c4
fbb8ba17c01180a24b51b68fd9807e4a28e561d5d344b2baf607eda92d77219aa57c54c52b8b
d9a1f00f4d4e63f193d3089c1a396bc81a9fc88206480dc4a57b5b488fb34e9ac384ce919b94
567443f6fe9eb3199ef1cfec5cf3343d1003de5a824a6b4ff7ae
        EAP-Message =
0x783711920d724d0c6d8215edc2c8106d2d5bdb5c0db3438661f24fa3325a92e0959ca3b202
333824e1799e966f487857983c73b9477548cc8430cb1d94afb8751ace106e5401388bb34457
7f99fa44d7daa1e3b429f24bcdfd74c26813fbb390a65854d14ce5b3f9a8a06830f6deea9271
b7f09a8f2786d0bda65dad5733155c3028f318317133f2fdaa4c8687ab457f4cc9f6d1f90203
010001a381fb3081f8301d0603551d0e04160414c653e0f09e4775e74119ec9d2ca877eea7d7
857c3081c80603551d230481c03081bd8014c653e0f09e4775e74119ec9d2ca877eea7d7857c
a18199a48196308193310b3009060355040613024652310f300d
        EAP-Message =
0x060355040813065261646975733112301006035504071309536f6d65776865726531153013
060355040a130c4578616d706c6520496e632e3120301e06092a864886f70d01090116116164
6d696e406578616d706c652e636f6d312630240603550403131d4578616d706c652043657274
6966696361746520417574686f72697479820900b7ca1f4a75b65c48300c0603551d13040530
030101ff300d06092a864886f70d0101050500038201010054813204c14a1e24209f2775a069
ec1ef24c75af5aeae0cd8fd867228eb1053d085cb7a41f825bef7c00509b6c16f5418140dd84
d04a6470f0066b95863ebdd930d7137d4b269a127b5ac5d8bb54
        EAP-Message = 0xa450a87daa867321e3c885c3
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x478ccb124489de59ab6dcf8f64d052f7
Finished request 550.
Going to the next request
Waking up in 4.7 seconds.
rad_recv: Access-Request packet from host 172.16.4.2 port 1812, id=138,
length=223
        User-Name = "{am=1}172E3FAD27897FBB29D016059C621B03 at WiMax.com"
        EAP-Message = 0x020500061500
        Message-Authenticator = 0x650835cee90bb974cdf638b73fcd2a0b
        NAS-Identifier = "Freeradius"
        NAS-IP-Address = 172.16.4.2
        Calling-Station-Id = "00-A0-0A-13-13-72"
        WiMAX-BS-Id = 0x000002010203
        NAS-Port-Type = 27
        Framed-MTU = 2000
        Service-Type = Framed-User
        WiMAX-GMT-Timezone-offset = 0
        WiMAX-Release = "1.0"
        WiMAX-Accounting-Capabilities = IP-Session-Based
        WiMAX-Hotlining-Capabilities = Hotline-Profile-Id
        WiMAX-Attr-1793 = 0x0000028a
        State = 0x478ccb124489de59ab6dcf8f64d052f7
+- entering group authorize {...}
++[preprocess] returns ok
++[mschap] returns noop
++[wimax] returns ok
[suffix] Looking up realm "WiMax.com" for User-Name =
"{am=1}172E3FAD27897FBB29D016059C621B03 at WiMax.com"
[suffix] Found realm "WiMax.com"
[suffix] Adding Stripped-User-Name =
"{am=1}172E3FAD27897FBB29D016059C621B03"
[suffix] Adding Realm = "WiMax.com"
[suffix] Authentication realm is LOCAL.
++[suffix] returns ok
[eap] EAP packet type response id 5 length 6
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/ttls
[eap] processing type ttls
[ttls] Authenticate
[ttls] processing EAP-TLS
[ttls] Received TLS ACK
[ttls] ACK handshake fragment handler
[ttls] eaptls_verify returned 1
[ttls] eaptls_process returned 13
++[eap] returns handled
Sending Access-Challenge of id 138 to 172.16.4.2 port 1812
        EAP-Message =
0x010602cb158000000aad9c453583b6807402da0b0d8c90c139a9a0ddef70b01c5fa9ee8ac5
1255bf935d536f69d45b60a86ca871ddfc2c67c15cd531a3fae5cf5dfccf9170560759968f21
e6020052bf6baeb29ebcd3e174c16a36a30ef060c4d110b63cea4f16a115717fa6a8ba515021
0f86dd7f31bde3a3c35117d3d0b991763b97041453c7aa22a068e26a3b931dddbc429d8bdc75
66b6077f51717c612d206261f862b672cff53abfb016b9b839160301020d0c0002090080f5bd
24429f55049a0764bc935fbb95edf33bca4152a811bf1895e8dbfebd93cebc81616f548086f0
fb025058c15c8cc5f35dad890892db51c300b8fd6b7ecd9001da
        EAP-Message =
0xbe526cba14255c8cec05d51acdc7c0aa97a19bf634ee550c72543d1d4927b0819129b99790
32cf1d098638b89741798e7e2c6854e368448190fa73d3b68b0001020080d14954812608d3ee
2cd467c9d9cc82e9b8985d9697a37d6f55a4ccec638fb00acb0c1fcc319ecf2424ef63f34a9e
ae614ac737a8196c7e812ef9421575874140c65ab0d8ac4d092541e4a6ea37180b0022ba3083
9099dfe279acb9694005ffc1a0c9c5c73fe8d0fbc365f4e8bd850ab91c4101a621bf6a9ce40e
e60977746c3c0100293beb89c04468412b3fb9cc298d4655c621ae4e66cfcbc5d4f32d45b2d1
2ac7d25539fa6d95a5b8c499e342a5b65b1c5106c99d1b35e9da
        EAP-Message =
0x835db11a36f83ca100b5b2ca091706d1d6d179ca093f0c058400ccdffc2c9e20bcbea1410c
ee9ae316b7346db3a6a222e773195dec7a26a2932522619bda9f577ad01aef49ca5dbef3cbd7
d2e58d2d77480dc5ea7040a7aa59be3be18d24d027b0d8d79d963301447928b6451b9aec63b0
65706957f8cdb30bf7be9aea5a8efe74d2bc279981e3c7856170d926575e9451606996ddc012
9bfaa37c7ee0a86b308ba5a214bf361376c1f72a082220dbdd4e1753c7b5f792b67886f083f9
29c881afc50ff4c103b34416030100040e000000
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x478ccb12438ade59ab6dcf8f64d052f7
Finished request 551.
Going to the next request
Waking up in 4.6 seconds.
rad_recv: Access-Request packet from host 172.16.4.2 port 1812, id=139,
length=425
        User-Name = "{am=1}172E3FAD27897FBB29D016059C621B03 at WiMax.com"
        EAP-Message =
0x020600d01580000000c6160301008610000082008019091b56b93c2dd93d6750a96e9c9dc6
04a460123d8d6b72a95bddc2b80645b03c1adad01f5fb131822813ade7a1d1db4799be842683
a508e70cb22e0f19ebbb0161140dc4320cc74a6898a57ec9a4ba09afdcb04900f900b9153f7d
6f221e485ada8f7fe9e836370dce412cafc5b7650f5cdefabfce5b8e83eef7c41c1b29451403
0100010116030100301d1813cf79828a23207e419b22109258f0bb833fc4a7dbf259c9276eb4
af13242a5d16fa9fcb25b2e9e60bc90d9151d0
        Message-Authenticator = 0x3dbbb76e82f0635a2a42821991fc3aa4
        NAS-Identifier = "Freeradius"
        NAS-IP-Address = 172.16.4.2
        Calling-Station-Id = "00-A0-0A-13-13-72"
        WiMAX-BS-Id = 0x000002010203
        NAS-Port-Type = 27
        Framed-MTU = 2000
        Service-Type = Framed-User
        WiMAX-GMT-Timezone-offset = 0
        WiMAX-Release = "1.0"
        WiMAX-Accounting-Capabilities = IP-Session-Based
        WiMAX-Hotlining-Capabilities = Hotline-Profile-Id
        WiMAX-Attr-1793 = 0x0000028a
        State = 0x478ccb12438ade59ab6dcf8f64d052f7
+- entering group authorize {...}
++[preprocess] returns ok
++[mschap] returns noop
++[wimax] returns ok
[suffix] Looking up realm "WiMax.com" for User-Name =
"{am=1}172E3FAD27897FBB29D016059C621B03 at WiMax.com"
[suffix] Found realm "WiMax.com"
[suffix] Adding Stripped-User-Name =
"{am=1}172E3FAD27897FBB29D016059C621B03"
[suffix] Adding Realm = "WiMax.com"
[suffix] Authentication realm is LOCAL.
++[suffix] returns ok
[eap] EAP packet type response id 6 length 208
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/ttls
[eap] processing type ttls
[ttls] Authenticate
[ttls] processing EAP-TLS
  TLS Length 198
[ttls] Length Included
[ttls] eaptls_verify returned 11
[ttls] <<< TLS 1.0 Handshake [length 0086], ClientKeyExchange
[ttls]     TLS_accept: SSLv3 read client key exchange A
[ttls] <<< TLS 1.0 ChangeCipherSpec [length 0001]
[ttls] <<< TLS 1.0 Handshake [length 0010], Finished
[ttls]     TLS_accept: SSLv3 read finished A
[ttls] >>> TLS 1.0 ChangeCipherSpec [length 0001]
[ttls]     TLS_accept: SSLv3 write change cipher spec A
[ttls] >>> TLS 1.0 Handshake [length 0010], Finished
[ttls]     TLS_accept: SSLv3 write finished A
[ttls]     TLS_accept: SSLv3 flush data
[ttls]     (other): SSL negotiation finished successfully
SSL Connection Established
[ttls] eaptls_process returned 13
++[eap] returns handled
Sending Access-Challenge of id 139 to 172.16.4.2 port 1812
        EAP-Message =
0x0107004515800000003b1403010001011603010030dca979f044c0aeda0da67eb60b0d7a02
7265933c924dd92c1d3ba9e02c7c623ff4a863c6d2033b2a97888d48714b8802
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x478ccb12428bde59ab6dcf8f64d052f7
Finished request 552.
Going to the next request
Waking up in 3.3 seconds.
rad_recv: Access-Request packet from host 172.16.4.2 port 1812, id=140,
length=409
        User-Name = "{am=1}172E3FAD27897FBB29D016059C621B03 at WiMax.com"
        EAP-Message =
0x020700c015001703010020c45c7d140d8783a758c9ecb656e69f1b4fc3cbc22382dbe0caff
1673e827cdfb17030100902d218bc577d463a8b1e2b50ab09206f3daeef02fcd91bd52e90f23
819f1a07654a3ba1a711f59e431ab93d3189dc860a74b9cd67febcb621a9438f8fd16160dec8
cbab6c3a21ef49c52939a6e98c56edf4d47e23ec0a53c3e15dbae0b28e92b68073bc17c0a95c
e757a5c183d05966cf63b4e0080127996ee7300527111c5e478bca2b1fedc90fdaace5a2bbe1
d46f1a
        Message-Authenticator = 0x31d57333c56c4b226b3665b572620ba2
        NAS-Identifier = "Freeradius"
        NAS-IP-Address = 172.16.4.2
        Calling-Station-Id = "00-A0-0A-13-13-72"
        WiMAX-BS-Id = 0x000002010203
        NAS-Port-Type = 27
        Framed-MTU = 2000
        Service-Type = Framed-User
        WiMAX-GMT-Timezone-offset = 0
        WiMAX-Release = "1.0"
        WiMAX-Accounting-Capabilities = IP-Session-Based
        WiMAX-Hotlining-Capabilities = Hotline-Profile-Id
        WiMAX-Attr-1793 = 0x0000028a
        State = 0x478ccb12428bde59ab6dcf8f64d052f7
+- entering group authorize {...}
++[preprocess] returns ok
++[mschap] returns noop
++[wimax] returns ok
[suffix] Looking up realm "WiMax.com" for User-Name =
"{am=1}172E3FAD27897FBB29D016059C621B03 at WiMax.com"
[suffix] Found realm "WiMax.com"
[suffix] Adding Stripped-User-Name =
"{am=1}172E3FAD27897FBB29D016059C621B03"
[suffix] Adding Realm = "WiMax.com"
[suffix] Authentication realm is LOCAL.
++[suffix] returns ok
[eap] EAP packet type response id 7 length 192
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/ttls
[eap] processing type ttls
[ttls] Authenticate
[ttls] processing EAP-TLS
[ttls] eaptls_verify returned 7
[ttls] Done initial handshake
[ttls] eaptls_process returned 7
[ttls] Session established.  Proceeding to decode tunneled attributes.
[ttls] Got tunneled request
        User-Name = "Silver2 at WiMax.com"
        MS-CHAP-Challenge = 0xd9f370a27454c8f24cb516abd89c288d
        MS-CHAP2-Response =
0x8b00d9f370a27454c8f24cb516abd89c288d00000000000000003d35ec9cbd8b5be8ba199d
30326911e6075fe803c3a48a5d
        FreeRADIUS-Proxied-To = 127.0.0.1
[ttls] Sending tunneled request
        User-Name = "Silver2 at WiMax.com"
        MS-CHAP-Challenge = 0xd9f370a27454c8f24cb516abd89c288d
        MS-CHAP2-Response =
0x8b00d9f370a27454c8f24cb516abd89c288d00000000000000003d35ec9cbd8b5be8ba199d
30326911e6075fe803c3a48a5d
        FreeRADIUS-Proxied-To = 127.0.0.1
        NAS-Identifier = "Freeradius"
        NAS-IP-Address = 172.16.4.2
        Calling-Station-Id = "00-A0-0A-13-13-72"
        WiMAX-BS-Id = 0x000002010203
        NAS-Port-Type = 27
        Framed-MTU = 2000
        Service-Type = Framed-User
        WiMAX-GMT-Timezone-offset = 0
        WiMAX-Release = "1.0"
        WiMAX-Accounting-Capabilities = IP-Session-Based
        WiMAX-Hotlining-Capabilities = Hotline-Profile-Id
        WiMAX-Attr-1793 = 0x0000028a
server inner-tunnel {
+- entering group authorize {...}
++[chap] returns noop
[mschap] Found MS-CHAP attributes.  Setting 'Auth-Type  = mschap'
++[mschap] returns ok
[suffix] Looking up realm "WiMax.com" for User-Name = "Silver2 at WiMax.com"
[suffix] Found realm "WiMax.com"
[suffix] Adding Stripped-User-Name = "Silver2"
[suffix] Adding Realm = "WiMax.com"
[suffix] Authentication realm is LOCAL.
++[suffix] returns ok
++[control] returns ok
[eap] No EAP-Message, not doing EAP
++[eap] returns noop
++[files] returns noop
[sql]   expand: %{User-Name} -> Silver2 at WiMax.com
[sql] sql_set_user escaped user --> 'Silver2 at WiMax.com'
rlm_sql (sql): Reserving sql socket id: 0
[sql]   expand: SELECT id, username, attribute, value, op          FROM
radcheck          WHERE username = BINARY '%{SQL-User-Name}'          ORDER
BY id -> SELECT id, username, attribute, value, op          FROM radcheck
WHERE username = BINARY 'Silver2 at WiMax.com'          ORDER BY id
[sql] User found in radcheck table
[sql]   expand: SELECT id, username, attribute, value, op          FROM
radreply          WHERE username = BINARY '%{SQL-User-Name}'          ORDER
BY id -> SELECT id, username, attribute, value, op          FROM radreply
WHERE username = BINARY 'Silver2 at WiMax.com'          ORDER BY id
[sql]   expand: SELECT groupname          FROM radusergroup         WHERE
username = BINARY '%{SQL-User-Name}'          ORDER BY priority -> SELECT
groupname          FROM radusergroup         WHERE username = BINARY
'Silver2 at WiMax.com'          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 = '4M-Silver'           ORDER
BY id
[sql] User found in group 4M-Silver
[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 = '4M-Silver'           ORDER
BY id
rlm_sql (sql): Released sql socket id: 0
++[sql] returns ok
++[expiration] returns noop
++[logintime] returns noop
[pap] Found existing Auth-Type, not changing it.
++[pap] returns noop
WARNING: You set Proxy-To-Realm = LOCAL, but the realm does not exist!
Cancelling invalid proxy request.
Found Auth-Type = MSCHAP
+- entering group MS-CHAP {...}
[mschap] Told to do MS-CHAPv2 for Silver2 at WiMax.com with NT-Password
[mschap] adding MS-CHAPv2 MPPE keys
++[mschap] returns ok
+- entering group post-auth {...}
[sql]   expand: %{User-Name} -> Silver2 at WiMax.com
[sql] sql_set_user escaped user --> 'Silver2 at WiMax.com'
[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 (
'Silver2 at WiMax.com',                           '',
'Access-Accept', '2010-10-20 13:36:35')
rlm_sql (sql) in sql_postauth: query is INSERT INTO radpostauth
(username, pass, reply, authdate)                           VALUES (
'Silver2 at WiMax.com',                           '',
'Access-Accept', '2010-10-20 13:36:35')
rlm_sql (sql): Reserving sql socket id: 4
rlm_sql (sql): Released sql socket id: 4
++[sql] returns ok
[sql_log] Processing sql_log_postauth
[sql_log]       expand: %{User-Name} -> Silver2 at WiMax.com
[sql_log]       expand: %{%{User-Name}:-DEFAULT} -> Silver2 at WiMax.com
[sql_log] sql_set_user escaped user --> 'Silver2 at WiMax.com'
[sql_log] WARNING: Deprecated conditional expansion ":-".  See "man unlang"
for details
[sql_log]       ... expanding second conditional
[sql_log]       expand: Chap-Password -> Chap-Password
[sql_log]       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
('Silver2 at WiMax.com', 'Chap-Password',                 'Access-Accept',
'2010-10-20 13:36:35');
[sql_log]       expand: /usr/local/var/log/radius/radacct/sql-relay ->
/usr/local/var/log/radius/radacct/sql-relay
++[sql_log] returns ok
} # server inner-tunnel
[ttls] Got tunneled reply code 2
        Framed-Filter-Id = "Silver"
        MS-CHAP2-Success =
0x8b533d38433645334446453936303744394437333431414438434335394545304644394637
443543463442
        MS-MPPE-Recv-Key = 0x6120b81ed669fe9f25bc6f78b2e3f860
        MS-MPPE-Send-Key = 0x8607a38d1b37202ce93c2b3eaa59349e
        MS-MPPE-Encryption-Policy = 0x00000001
        MS-MPPE-Encryption-Types = 0x00000006
[ttls] Got tunneled Access-Accept
[ttls] Got MS-CHAP2-Success, tunneling it to the client in a challenge.
++[eap] returns handled
Sending Access-Challenge of id 140 to 172.16.4.2 port 1812
        EAP-Message =
0x0108005f1580000000551703010050732325854414b144cb0eec24b7c8109439fe1a8b2861
2081fe9cc5091d883358215d4490c6a18f408959f4bfe9364db18ba45720b7aaafaf32c3268d
28b0a59de65c8dadfadbbdd0806cb9b8595ea5d8
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x478ccb124184de59ab6dcf8f64d052f7
Finished request 553.
Going to the next request
Waking up in 3.2 seconds.
rad_recv: Access-Request packet from host 172.16.4.2 port 1812, id=141,
length=223
        User-Name = "{am=1}172E3FAD27897FBB29D016059C621B03 at WiMax.com"
        EAP-Message = 0x020800061500
        Message-Authenticator = 0xb63cdc0036db5df04e318a3f5f952f25
        NAS-Identifier = "Freeradius"
^C''



root at ubuntu:/usr/local/etc/raddb/sites-available# ''
root at ubuntu:/usr/local/etc/raddb/sites-available#
root at ubuntu:/usr/local/etc/raddb/sites-available#
root at ubuntu:/usr/local/etc/raddb/sites-available#
root at ubuntu:/usr/local/etc/raddb/sites-available# radiusd -X
FreeRADIUS Version 2.1.10, for host i686-pc-linux-gnu, built on Jun 21 2010
at 14:47:46
Copyright (C) 1999-2009 The FreeRADIUS server project and contributors.
There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A
PARTICULAR PURPOSE.
You may redistribute copies of FreeRADIUS under the terms of the
GNU General Public License v2.
Starting - reading configuration files ...
including configuration file /usr/local/etc/raddb/radiusd.conf
including configuration file /usr/local/etc/raddb/proxy.conf
including configuration file /usr/local/etc/raddb/clients.conf
including configuration file
/usr/local/etc/raddb/sites-available/dynamic-clients
including files in directory /usr/local/etc/raddb/modules/
including configuration file /usr/local/etc/raddb/modules/passwd
including configuration file /usr/local/etc/raddb/modules/mac2vlan
including configuration file /usr/local/etc/raddb/modules/policy
including configuration file /usr/local/etc/raddb/modules/wimax
including configuration file /usr/local/etc/raddb/modules/ippool
including configuration file /usr/local/etc/raddb/modules/radutmp
including configuration file /usr/local/etc/raddb/modules/smsotp
including configuration file /usr/local/etc/raddb/modules/echo
including configuration file /usr/local/etc/raddb/modules/expr
including configuration file /usr/local/etc/raddb/modules/pam
including configuration file /usr/local/etc/raddb/modules/inner-eap
including configuration file /usr/local/etc/raddb/modules/logintime
including configuration file /usr/local/etc/raddb/modules/ldap
including configuration file /usr/local/etc/raddb/modules/pap
including configuration file /usr/local/etc/raddb/modules/ntlm_auth
including configuration file /usr/local/etc/raddb/modules/preprocess
including configuration file /usr/local/etc/raddb/modules/unix
including configuration file /usr/local/etc/raddb/modules/attr_rewrite
including configuration file /usr/local/etc/raddb/modules/etc_group
including configuration file /usr/local/etc/raddb/modules/linelog
including configuration file
/usr/local/etc/raddb/modules/sqlcounter_expire_on_login
including configuration file /usr/local/etc/raddb/modules/digest
including configuration file /usr/local/etc/raddb/modules/otp
including configuration file /usr/local/etc/raddb/modules/realm
including configuration file /usr/local/etc/raddb/modules/acct_unique
including configuration file /usr/local/etc/raddb/modules/attr_filter
including configuration file /usr/local/etc/raddb/modules/perl
including configuration file /usr/local/etc/raddb/modules/krb5
including configuration file /usr/local/etc/raddb/modules/checkval
including configuration file /usr/local/etc/raddb/modules/files
including configuration file /usr/local/etc/raddb/modules/cui
including configuration file /usr/local/etc/raddb/modules/exec
including configuration file /usr/local/etc/raddb/modules/expiration
including configuration file /usr/local/etc/raddb/modules/smbpasswd
including configuration file /usr/local/etc/raddb/modules/detail.log
including configuration file /usr/local/etc/raddb/modules/mschap
including configuration file /usr/local/etc/raddb/modules/sradutmp
including configuration file /usr/local/etc/raddb/modules/counter
including configuration file /usr/local/etc/raddb/modules/mac2ip
including configuration file /usr/local/etc/raddb/modules/detail
including configuration file /usr/local/etc/raddb/modules/detail.example.com
including configuration file /usr/local/etc/raddb/modules/chap
including configuration file /usr/local/etc/raddb/modules/sql_log
including configuration file /usr/local/etc/raddb/modules/always
including configuration file /usr/local/etc/raddb/eap.conf
including configuration file /usr/local/etc/raddb/sql.conf
including configuration file /usr/local/etc/raddb/sql/mysql/dialup.conf
including configuration file /usr/local/etc/raddb/policy.conf
including files in directory /usr/local/etc/raddb/sites-enabled/
including configuration file /usr/local/etc/raddb/sites-enabled/default
including configuration file
/usr/local/etc/raddb/sites-enabled/control-socket
including configuration file /usr/local/etc/raddb/sites-enabled/inner-tunnel
main {
        allow_core_dumps = no
}
including dictionary file /usr/local/etc/raddb/dictionary
main {
        prefix = "/usr/local"
        localstatedir = "/usr/local/var"
        logdir = "/usr/local/var/log/radius"
        libdir = "/usr/local/lib"
        radacctdir = "/usr/local/var/log/radius/radacct"
        hostname_lookups = no
        max_request_time = 30
        cleanup_delay = 5
        max_requests = 1024
        pidfile = "/usr/local/var/run/radiusd/radiusd.pid"
        checkrad = "/usr/local/sbin/checkrad"
        debug_level = 0
        proxy_requests = yes
 log {
        stripped_names = no
        auth = no
        auth_badpass = no
        auth_goodpass = no
 }
 security {
        max_attributes = 200
        reject_delay = 1
        status_server = yes
 }
}
radiusd: #### Loading Realms and Home Servers ####
 realm WiMax.com {
 }
radiusd: #### Loading Clients ####
 client localhost {
        ipaddr = 127.0.0.1
        require_message_authenticator = no
        secret = "testing123"
        nastype = "other"
 }
 client dynamic {
        ipaddr = 192.168.0.0
        netmask = 16
        require_message_authenticator = no
        dynamic_clients = "dynamic_client_server"
        lifetime = 86400
 }
 client dynamic {
        ipaddr = 172.16.0.0
        netmask = 16
        require_message_authenticator = no
        dynamic_clients = "dynamic_client_server"
        lifetime = 86400
 }
radiusd: #### Instantiating modules ####
 instantiate {
 Module: Linked to module rlm_exec
 Module: Instantiating exec
  exec {
        wait = no
        input_pairs = "request"
        shell_escape = yes
  }
 Module: Linked to module rlm_expr
 Module: Instantiating expr
 Module: Linked to module rlm_expiration
 Module: Instantiating expiration
  expiration {
        reply-message = "Password Has Expired  "
  }
 Module: Linked to module rlm_logintime
 Module: Instantiating logintime
  logintime {
        reply-message = "You are calling outside your allowed timespan  "
        minimum-timeout = 60
  }
 }
radiusd: #### Loading Virtual Servers ####
server dynamic_client_server {
 modules {
 Module: Checking authorize {...} for more modules to load
 Module: Linked to module rlm_always
 Module: Instantiating ok
  always ok {
        rcode = "ok"
        simulcount = 0
        mpp = no
  }
 } # modules
} # server
server inner-tunnel {
 modules {
 Module: Checking authenticate {...} for more modules to load
 Module: Linked to module rlm_pap
 Module: Instantiating pap
  pap {
        encryption_scheme = "auto"
        auto_header = no
  }
 Module: Linked to module rlm_chap
 Module: Instantiating chap
 Module: Linked to module rlm_mschap
 Module: Instantiating mschap
  mschap {
        use_mppe = yes
        require_encryption = no
        require_strong = no
        with_ntdomain_hack = no
  }
 Module: Linked to module rlm_unix
 Module: Instantiating unix
  unix {
        radwtmp = "/usr/local/var/log/radius/radwtmp"
  }
 Module: Linked to module rlm_eap
 Module: Instantiating eap
  eap {
        default_eap_type = "md5"
        timer_expire = 60
        ignore_unknown_eap_types = no
        cisco_accounting_username_bug = no
        max_sessions = 4096
  }
 Module: Linked to sub-module rlm_eap_md5
 Module: Instantiating eap-md5
 Module: Linked to sub-module rlm_eap_leap
 Module: Instantiating eap-leap
 Module: Linked to sub-module rlm_eap_gtc
 Module: Instantiating eap-gtc
   gtc {
        challenge = "Password: "
        auth_type = "PAP"
   }
 Module: Linked to sub-module rlm_eap_tls
 Module: Instantiating eap-tls
   tls {
        rsa_key_exchange = no
        dh_key_exchange = yes
        rsa_key_length = 512
        dh_key_length = 512
        verify_depth = 0
        pem_file_type = yes
        private_key_file = "/usr/local/etc/raddb/certs/server.pem"
        certificate_file = "/usr/local/etc/raddb/certs/server.pem"
        CA_file = "/usr/local/etc/raddb/certs/ca.pem"
        private_key_password = "whatever"
        dh_file = "/usr/local/etc/raddb/certs/dh"
        random_file = "/usr/local/etc/raddb/certs/random"
        fragment_size = 1024
        include_length = yes
        check_crl = no
        cipher_list = "DEFAULT"
        make_cert_command = "/usr/local/etc/raddb/certs/bootstrap"
    cache {
        enable = no
        lifetime = 24
        max_entries = 255
    }
   }
 Module: Linked to sub-module rlm_eap_ttls
 Module: Instantiating eap-ttls
   ttls {
        default_eap_type = "md5"
        copy_request_to_tunnel = yes
        use_tunneled_reply = yes
        virtual_server = "inner-tunnel"
        include_length = yes
   }
 Module: Linked to sub-module rlm_eap_peap
 Module: Instantiating eap-peap
   peap {
        default_eap_type = "mschapv2"
        copy_request_to_tunnel = no
        use_tunneled_reply = no
        proxy_tunneled_request_as_eap = yes
        virtual_server = "inner-tunnel"
   }
 Module: Linked to sub-module rlm_eap_mschapv2
 Module: Instantiating eap-mschapv2
   mschapv2 {
        with_ntdomain_hack = no
   }
 Module: Checking authorize {...} for more modules to load
 Module: Linked to module rlm_realm
 Module: Instantiating suffix
  realm suffix {
        format = "suffix"
        delimiter = "@"
        ignore_default = no
        ignore_null = no
  }
 Module: Linked to module rlm_files
 Module: Instantiating files
  files {
        usersfile = "/usr/local/etc/raddb/users"
        acctusersfile = "/usr/local/etc/raddb/acct_users"
        preproxy_usersfile = "/usr/local/etc/raddb/preproxy_users"
        compat = "no"
  }
 Module: Linked to module rlm_sql
 Module: Instantiating sql
  sql {
        driver = "rlm_sql_mysql"
        server = "localhost"
        port = ""
        login = "root"
        password = "unl0ck"
        radius_db = "radius"
        read_groups = yes
        sqltrace = no
        sqltracefile = "/usr/local/var/log/radius/sqltrace.sql"
        readclients = no
        deletestalesessions = yes
        num_sql_socks = 5
        lifetime = 0
        max_queries = 0
        sql_user_name = "%{User-Name}"
        default_user_profile = ""
        nas_query = "SELECT id, nasname, shortname, type, secret, server
FROM nas"
        authorize_check_query = "SELECT id, username, attribute, value, op
FROM radcheck          WHERE username = BINARY '%{SQL-User-Name}'
ORDER BY id"
        authorize_reply_query = "SELECT id, username, attribute, value, op
FROM radreply          WHERE username = BINARY '%{SQL-User-Name}'
ORDER BY id"
        authorize_group_check_query = "SELECT id, groupname, attribute,
Value, op           FROM radgroupcheck           WHERE groupname =
'%{Sql-Group}'           ORDER BY id"
        authorize_group_reply_query = "SELECT id, groupname, attribute,
value, op           FROM radgroupreply           WHERE groupname =
'%{Sql-Group}'           ORDER BY id"
        accounting_onoff_query = "         UPDATE radacct           SET
acctstoptime       =  '%S',              acctsessiontime    =
unix_timestamp('%S') -
unix_timestamp(acctstarttime),              acctterminatecause =
'%{Acct-Terminate-Cause}',              acctstopdelay      =
%{%{Acct-Delay-Time}:-0}           WHERE acctstoptime IS NULL           AND
nasipaddress      =  '%{NAS-IP-Address}'           AND acctstarttime     <=
'%S'"
        accounting_update_query = "           UPDATE radacct           SET
framedipaddress = '%{Framed-IP-Address}',              acctsessiontime     =
'%{Acct-Session-Time}',              acctinputoctets     =
'%{%{Acct-Input-Gigawords}:-0}'  << 32 |
'%{%{Acct-Input-Octets}:-0}',              acctoutputoctets    =
'%{%{Acct-Output-Gigawords}:-0}' << 32 |
'%{%{Acct-Output-Octets}:-0}'           WHERE acctsessionid =
'%{Acct-Session-Id}'           AND username        = '%{SQL-User-Name}'
AND nasipaddress    = '%{NAS-IP-Address}'"
        accounting_update_query_alt = "           INSERT INTO radacct
(acctsessionid,    acctuniqueid,      username,              realm,
nasipaddress,      nasportid,              nasporttype,      acctstarttime,
acctsessiontime,              acctauthentic,    connectinfo_start,
acctinputoctets,              acctoutputoctets, calledstationid,
callingstationid,              servicetype,      framedprotocol,
framedipaddress,              acctstartdelay,   xascendsessionsvrkey)
VALUES             ('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}',
'%{SQL-User-Name}',              '%{Realm}', '%{NAS-IP-Address}',
'%{NAS-Port}',              '%{NAS-Port-Type}',              DATE_SUB('%S',
INTERVAL (%{%{Acct-Session-Time}:-0} +
%{%{Acct-Delay-Time}:-0}) SECOND),
'%{Acct-Session-Time}',              '%{Acct-Authentic}', '',
'%{%{Acct-Input-Gigawords}:-0}' << 32 |
'%{%{Acct-Input-Octets}:-0}',              '%{%{Acct-Output-Gigawords}:-0}'
<< 32 |              '%{%{Acct-Output-Octets}:-0}',
'%{Called-Station-Id}', '%{Calling-Station-Id}',
'%{Service-Type}', '%{Framed-Protocol}',
'%{Framed-IP-Address}',              '0', '%{X-Ascend-Session-Svr-Key}')"
        accounting_start_query = "           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}',
'%{%{Acct-Delay-Time}:-0}', '0', '%{X-Ascend-Session-Svr-Key}')"
        accounting_start_query_alt = "           UPDATE radacct SET
acctstarttime     = '%S',              acctstartdelay    =
'%{%{Acct-Delay-Time}:-0}',              connectinfo_start =
'%{Connect-Info}'           WHERE acctsessionid  = '%{Acct-Session-Id}'
AND username         = '%{SQL-User-Name}'           AND nasipaddress     =
'%{NAS-IP-Address}'"
        accounting_stop_query = "           UPDATE radacct SET
acctstoptime       = '%S',              acctsessiontime    =
'%{Acct-Session-Time}',              acctinputoctets    =
'%{%{Acct-Input-Gigawords}:-0}' << 32 |
'%{%{Acct-Input-Octets}:-0}',              acctoutputoctets   =
'%{%{Acct-Output-Gigawords}:-0}' << 32 |
'%{%{Acct-Output-Octets}:-0}',              acctterminatecause =
'%{Acct-Terminate-Cause}',              acctstopdelay      =
'%{%{Acct-Delay-Time}:-0}',              connectinfo_stop   =
'%{Connect-Info}'           WHERE acctsessionid   = '%{Acct-Session-Id}'
AND username          = '%{SQL-User-Name}'           AND nasipaddress      =
'%{NAS-IP-Address}'"
        accounting_stop_query_alt = "           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)           VALUES             ('%{Acct-Session-Id}',
'%{Acct-Unique-Session-Id}',              '%{SQL-User-Name}',
'%{Realm}', '%{NAS-IP-Address}', '%{NAS-Port}',
'%{NAS-Port-Type}',              DATE_SUB('%S',                  INTERVAL
(%{%{Acct-Session-Time}:-0} +                  %{%{Acct-Delay-Time}:-0})
SECOND),              '%S', '%{Acct-Session-Time}', '%{Acct-Authentic}', '',
'%{Connect-Info}',              '%{%{Acct-Input-Gigawords}:-0}' << 32 |
'%{%{Acct-Input-Octets}:-0}',              '%{%{Acct-Output-Gigawords}:-0}'
<< 32 |              '%{%{Acct-Output-Octets}:-0}',
'%{Called-Station-Id}', '%{Calling-Station-Id}',
'%{Acct-Terminate-Cause}',              '%{Service-Type}',
'%{Framed-Protocol}', '%{Framed-IP-Address}',              '0',
'%{%{Acct-Delay-Time}:-0}')"
        group_membership_query = "SELECT groupname          FROM
radusergroup         WHERE username = BINARY '%{SQL-User-Name}'
ORDER BY priority"
        connect_failure_retry_delay = 60
        simul_count_query = ""
        simul_verify_query = "SELECT radacctid, acctsessionid, username,
nasipaddress, nasportid, framedipaddress,
callingstationid, framedprotocol                                FROM radacct
WHERE username = '%{SQL-User-Name}'                                AND
acctstoptime IS NULL"
        postauth_query = "INSERT INTO radpostauth
(username, pass, reply, authdate)                           VALUES (
'%{User-Name}',
'%{%{User-Password}:-%{Chap-Password}}',
'%{reply:Packet-Type}', '%S')"
        safe-characters =
"@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /"
  }
rlm_sql (sql): Driver rlm_sql_mysql (module rlm_sql_mysql) loaded and linked
rlm_sql (sql): Attempting to connect to root at localhost:/radius
rlm_sql (sql): starting 0
rlm_sql (sql): Attempting to connect rlm_sql_mysql #0
rlm_sql_mysql: Starting connect to MySQL server for #0
rlm_sql (sql): Connected new DB handle, #0
rlm_sql (sql): starting 1
rlm_sql (sql): Attempting to connect rlm_sql_mysql #1
rlm_sql_mysql: Starting connect to MySQL server for #1
rlm_sql (sql): Connected new DB handle, #1
rlm_sql (sql): starting 2
rlm_sql (sql): Attempting to connect rlm_sql_mysql #2
rlm_sql_mysql: Starting connect to MySQL server for #2
rlm_sql (sql): Connected new DB handle, #2
rlm_sql (sql): starting 3
rlm_sql (sql): Attempting to connect rlm_sql_mysql #3
rlm_sql_mysql: Starting connect to MySQL server for #3
rlm_sql (sql): Connected new DB handle, #3
rlm_sql (sql): starting 4
rlm_sql (sql): Attempting to connect rlm_sql_mysql #4
rlm_sql_mysql: Starting connect to MySQL server for #4
rlm_sql (sql): Connected new DB handle, #4
 Module: Checking session {...} for more modules to load
 Module: Linked to module rlm_radutmp
 Module: Instantiating radutmp
  radutmp {
        filename = "/usr/local/var/log/radius/radutmp"
        username = "%{User-Name}"
        case_sensitive = yes
        check_with_nas = yes
        perm = 384
        callerid = yes
  }
 Module: Checking post-proxy {...} for more modules to load
 Module: Checking post-auth {...} for more modules to load
 Module: Linked to module rlm_sql_log
 Module: Instantiating sql_log
  sql_log {
        path = "/usr/local/var/log/radius/radacct/sql-relay"
        Post-Auth = "INSERT INTO radpostauth                     (username,
pass, reply, authdate) VALUES                        ('%{User-Name}',
'%{User-Password:-Chap-Password}',             '%{reply:Packet-Type}',
'%S');"
        sql_user_name = "%{%{User-Name}:-DEFAULT}"
        utf8 = no
        safe-characters =
"@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /"
  }
 Module: Linked to module rlm_attr_filter
 Module: Instantiating attr_filter.access_reject
  attr_filter attr_filter.access_reject {
        attrsfile = "/usr/local/etc/raddb/attrs.access_reject"
        key = "%{User-Name}"
  }
 } # modules
} # server
server {
 modules {
 Module: Checking authenticate {...} for more modules to load
 Module: Instantiating attr_filter.access_challenge
  attr_filter attr_filter.access_challenge {
        attrsfile = "/usr/local/etc/raddb/attrs.access_challenge"
        key = "%{User-Name}"
  }
 Module: Instantiating handled
  always handled {
        rcode = "handled"
        simulcount = 0
        mpp = no
  }
 Module: Checking authorize {...} for more modules to load
 Module: Linked to module rlm_preprocess
 Module: Instantiating preprocess
  preprocess {
        huntgroups = "/usr/local/etc/raddb/huntgroups"
        hints = "/usr/local/etc/raddb/hints"
        with_ascend_hack = no
        ascend_channels_per_line = 23
        with_ntdomain_hack = no
        with_specialix_jetstream_hack = no
        with_cisco_vsa_hack = no
        with_alvarion_vsa_hack = no
  }
 Module: Linked to module rlm_wimax
 Module: Instantiating wimax
  wimax {
        delete_mppe_keys = yes
  }
 Module: Checking preacct {...} for more modules to load
 Module: Linked to module rlm_acct_unique
 Module: Instantiating acct_unique
  acct_unique {
        key = "User-Name, Acct-Session-Id, NAS-IP-Address,
Client-IP-Address, NAS-Port"
  }
 Module: Checking accounting {...} for more modules to load
 Module: Linked to module rlm_detail
 Module: Instantiating detail
  detail {
        detailfile =
"/usr/local/var/log/radius/radacct/%{Client-IP-Address}/detail-%Y%m%d"
        header = "%t"
        detailperm = 384
        dirperm = 493
        locking = no
        log_packet_header = no
  }
 Module: Instantiating attr_filter.accounting_response
  attr_filter attr_filter.accounting_response {
        attrsfile = "/usr/local/etc/raddb/attrs.accounting_response"
        key = "%{User-Name}"
  }
 Module: Checking session {...} for more modules to load
 Module: Checking post-proxy {...} for more modules to load
 Module: Checking post-auth {...} for more modules to load
 } # modules
} # server
radiusd: #### Opening IP addresses and Ports ####
listen {
        type = "auth"
        ipaddr = *
        port = 0
}
listen {
        type = "acct"
        ipaddr = *
        port = 0
}
listen {
        type = "control"
 listen {
        socket = "/usr/local/var/run/radiusd/radiusd.sock"
 }
}
Listening on authentication address * port 1812
Listening on accounting address * port 1813
Listening on command file /usr/local/var/run/radiusd/radiusd.sock
Listening on proxy address * port 1814
Ready to process requests.
rad_recv: Access-Request packet from host 172.16.4.2 port 1812, id=141,
length=223
server dynamic_client_server {
rlm_sql (sql): Reserving sql socket id: 4
rlm_sql (sql): Released sql socket id: 4
rlm_sql (sql): Reserving sql socket id: 3
rlm_sql (sql): Released sql socket id: 3
rlm_sql (sql): Reserving sql socket id: 2
rlm_sql (sql): Released sql socket id: 2
rlm_sql (sql): Reserving sql socket id: 1
rlm_sql (sql): Released sql socket id: 1
} # server dynamic_client_server
- Added client 172.16.4.2 with shared secret unl0ck
rad_recv: Access-Request packet from host 172.16.4.2 port 1812, id=141,
length=223
        User-Name = "{am=1}172E3FAD27897FBB29D016059C621B03 at WiMax.com"
        EAP-Message = 0x020800061500
        Message-Authenticator = 0xb63cdc0036db5df04e318a3f5f952f25
        NAS-Identifier = "Freeradius"
        NAS-IP-Address = 172.16.4.2
        Calling-Station-Id = "00-A0-0A-13-13-72"
        WiMAX-BS-Id = 0x000002010203
        NAS-Port-Type = 27
        Framed-MTU = 2000
        Service-Type = Framed-User
        WiMAX-GMT-Timezone-offset = 0
        WiMAX-Release = "1.0"
        WiMAX-Accounting-Capabilities = IP-Session-Based
        WiMAX-Hotlining-Capabilities = Hotline-Profile-Id
        WiMAX-Attr-1793 = 0x0000028a
        State = 0x478ccb124184de59ab6dcf8f64d052f7
+- entering group authorize {...}
++[preprocess] returns ok
++[mschap] returns noop
++[wimax] returns ok
[suffix] Looking up realm "WiMax.com" for User-Name =
"{am=1}172E3FAD27897FBB29D016059C621B03 at WiMax.com"
[suffix] Found realm "WiMax.com"
[suffix] Adding Stripped-User-Name =
"{am=1}172E3FAD27897FBB29D016059C621B03"
[suffix] Adding Realm = "WiMax.com"
[suffix] Authentication realm is LOCAL.
++[suffix] returns ok
[eap] EAP packet type response id 8 length 6
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
+- entering group authenticate {...}
rlm_eap: No EAP session matching the State variable.
[eap] Either EAP-request timed out OR EAP-response to an unknown EAP-request
[eap] Failed in handler
++[eap] returns invalid
Failed to authenticate the user.
Using Post-Auth-Type Reject
+- entering group REJECT {...}
[sql]   expand: %{User-Name} ->
{am=1}172E3FAD27897FBB29D016059C621B03 at WiMax.com
[sql] sql_set_user escaped user -->
'{am=1}172E3FAD27897FBB29D016059C621B03 at WiMax.com'
[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 (
'=7Bam=3D1=7D172E3FAD27897FBB29D016059C621B03 at WiMax.com',
'',                           'Access-Reject', '2010-10-20 13:36:50')
rlm_sql (sql) in sql_postauth: query is INSERT INTO radpostauth
(username, pass, reply, authdate)                           VALUES (
'=7Bam=3D1=7D172E3FAD27897FBB29D016059C621B03 at WiMax.com',
'',                           'Access-Reject', '2010-10-20 13:36:50')
rlm_sql (sql): Reserving sql socket id: 0
rlm_sql (sql): Released sql socket id: 0
++[sql] returns ok
[attr_filter.access_reject]     expand: %{User-Name} ->
{am=1}172E3FAD27897FBB29D016059C621B03 at WiMax.com
 attr_filter: Matched entry DEFAULT at line 11
++[attr_filter.access_reject] returns updated
Delaying reject of request 0 for 1 seconds
Going to the next request
Waking up in 0.9 seconds.
Sending delayed reject for request 0
Sending Access-Reject of id 141 to 172.16.4.2 port 1812
Waking up in 4.9 seconds.
Cleaning up request 0 ID 141 with timestamp +2
Ready to process requests.
rad_recv: Access-Request packet from host 172.16.4.2 port 1812, id=142,
length=252
        User-Name = "{am=1}A3D22E436B0C31DAC3639DCE50CB7B1E at WiMax.com"
        EAP-Message =
0x02010035017b616d3d317d4133443232453433364230433331444143333633394443453530
4342374231454057694d61782e636f6d
        Message-Authenticator = 0xab8201d1c8d310374d9e9cb69c7fe45a
        NAS-Identifier = "Freeradius"
        NAS-IP-Address = 172.16.4.2
        Calling-Station-Id = "00-A0-0A-13-13-72"
        WiMAX-BS-Id = 0x000002010203
        NAS-Port-Type = 27
        Framed-MTU = 2000
        Service-Type = Framed-User
        WiMAX-GMT-Timezone-offset = 0
        WiMAX-Release = "1.0"
        WiMAX-Accounting-Capabilities = IP-Session-Based
        WiMAX-Hotlining-Capabilities = Hotline-Profile-Id
        WiMAX-Attr-1793 = 0x0000028a
+- entering group authorize {...}
++[preprocess] returns ok
++[mschap] returns noop
++[wimax] returns ok
[suffix] Looking up realm "WiMax.com" for User-Name =
"{am=1}A3D22E436B0C31DAC3639DCE50CB7B1E at WiMax.com"
[suffix] Found realm "WiMax.com"
[suffix] Adding Stripped-User-Name =
"{am=1}A3D22E436B0C31DAC3639DCE50CB7B1E"
[suffix] Adding Realm = "WiMax.com"
[suffix] Authentication realm is LOCAL.
++[suffix] returns ok
[eap] EAP packet type response id 1 length 53
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
++[files] returns noop
[sql]   expand: %{User-Name} ->
{am=1}A3D22E436B0C31DAC3639DCE50CB7B1E at WiMax.com
[sql] sql_set_user escaped user -->
'{am=1}A3D22E436B0C31DAC3639DCE50CB7B1E at WiMax.com'
rlm_sql (sql): Reserving sql socket id: 4
[sql]   expand: SELECT id, username, attribute, value, op          FROM
radcheck          WHERE username = BINARY '%{SQL-User-Name}'          ORDER
BY id -> SELECT id, username, attribute, value, op          FROM radcheck
WHERE username = BINARY
'=7Bam=3D1=7DA3D22E436B0C31DAC3639DCE50CB7B1E at WiMax.com'          ORDER BY
id
[sql]   expand: SELECT groupname          FROM radusergroup         WHERE
username = BINARY '%{SQL-User-Name}'          ORDER BY priority -> SELECT
groupname          FROM radusergroup         WHERE username = BINARY
'=7Bam=3D1=7DA3D22E436B0C31DAC3639DCE50CB7B1E at WiMax.com'          ORDER BY
priority
rlm_sql (sql): Released sql socket id: 4
[sql] User {am=1}A3D22E436B0C31DAC3639DCE50CB7B1E at WiMax.com not found
++[sql] returns notfound
++[expiration] returns noop
++[logintime] returns noop
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] EAP Identity
[eap] processing type md5
rlm_eap_md5: Issuing Challenge
++[eap] returns handled
Sending Access-Challenge of id 142 to 172.16.4.2 port 1812
        EAP-Message = 0x010200160410e48b4edeff4bd80f302e7a0f1b529edc
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x5176890251748deb6482bebd55b3e66d
Finished request 1.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 172.16.4.2 port 1812, id=143,
length=223
        User-Name = "{am=1}A3D22E436B0C31DAC3639DCE50CB7B1E at WiMax.com"
        EAP-Message = 0x020200060315
        Message-Authenticator = 0x00e934eadcef5e9a33d9b76124541842
        NAS-Identifier = "Freeradius"
        NAS-IP-Address = 172.16.4.2
        Calling-Station-Id = "00-A0-0A-13-13-72"
        WiMAX-BS-Id = 0x000002010203
        NAS-Port-Type = 27
        Framed-MTU = 2000
        Service-Type = Framed-User
        WiMAX-GMT-Timezone-offset = 0
        WiMAX-Release = "1.0"
        WiMAX-Accounting-Capabilities = IP-Session-Based
        WiMAX-Hotlining-Capabilities = Hotline-Profile-Id
        WiMAX-Attr-1793 = 0x0000028a
        State = 0x5176890251748deb6482bebd55b3e66d
+- entering group authorize {...}
++[preprocess] returns ok
++[mschap] returns noop
++[wimax] returns ok
[suffix] Looking up realm "WiMax.com" for User-Name =
"{am=1}A3D22E436B0C31DAC3639DCE50CB7B1E at WiMax.com"
[suffix] Found realm "WiMax.com"
[suffix] Adding Stripped-User-Name =
"{am=1}A3D22E436B0C31DAC3639DCE50CB7B1E"
[suffix] Adding Realm = "WiMax.com"
[suffix] Authentication realm is LOCAL.
++[suffix] returns ok
[eap] EAP packet type response id 2 length 6
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
++[files] returns noop
[sql]   expand: %{User-Name} ->
{am=1}A3D22E436B0C31DAC3639DCE50CB7B1E at WiMax.com
[sql] sql_set_user escaped user -->
'{am=1}A3D22E436B0C31DAC3639DCE50CB7B1E at WiMax.com'
rlm_sql (sql): Reserving sql socket id: 3
[sql]   expand: SELECT id, username, attribute, value, op          FROM
radcheck          WHERE username = BINARY '%{SQL-User-Name}'          ORDER
BY id -> SELECT id, username, attribute, value, op          FROM radcheck
WHERE username = BINARY
'=7Bam=3D1=7DA3D22E436B0C31DAC3639DCE50CB7B1E at WiMax.com'          ORDER BY
id
[sql]   expand: SELECT groupname          FROM radusergroup         WHERE
username = BINARY '%{SQL-User-Name}'          ORDER BY priority -> SELECT
groupname          FROM radusergroup         WHERE username = BINARY
'=7Bam=3D1=7DA3D22E436B0C31DAC3639DCE50CB7B1E at WiMax.com'          ORDER BY
priority
rlm_sql (sql): Released sql socket id: 3
[sql] User {am=1}A3D22E436B0C31DAC3639DCE50CB7B1E at WiMax.com not found
++[sql] returns notfound
++[expiration] returns noop
++[logintime] returns noop
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP NAK
[eap] EAP-NAK asked for EAP-Type/ttls
[eap] processing type tls
[tls] Initiate
[tls] Start returned 1
++[eap] returns handled
Sending Access-Challenge of id 143 to 172.16.4.2 port 1812
        EAP-Message = 0x010300061520
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x5176890250759ceb6482bebd55b3e66d
Finished request 2.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 172.16.4.2 port 1812, id=144,
length=305
        User-Name = "{am=1}A3D22E436B0C31DAC3639DCE50CB7B1E at WiMax.com"
        EAP-Message =
0x0203005815800000004e16030100490100004503014ba56dc97006b3df82def037b2ef02e4
498e237e06617e6d38efab3255a9e80e00001e00390038003500160013000a00330032002f00
15001200090014001100080100
        Message-Authenticator = 0x95cd7a58a5e4df3c1209216284084a22
        NAS-Identifier = "Freeradius"
        NAS-IP-Address = 172.16.4.2
        Calling-Station-Id = "00-A0-0A-13-13-72"
        WiMAX-BS-Id = 0x000002010203
        NAS-Port-Type = 27
        Framed-MTU = 2000
        Service-Type = Framed-User
        WiMAX-GMT-Timezone-offset = 0
        WiMAX-Release = "1.0"
        WiMAX-Accounting-Capabilities = IP-Session-Based
        WiMAX-Hotlining-Capabilities = Hotline-Profile-Id
        WiMAX-Attr-1793 = 0x0000028a
        State = 0x5176890250759ceb6482bebd55b3e66d
+- entering group authorize {...}
++[preprocess] returns ok
++[mschap] returns noop
++[wimax] returns ok
[suffix] Looking up realm "WiMax.com" for User-Name =
"{am=1}A3D22E436B0C31DAC3639DCE50CB7B1E at WiMax.com"
[suffix] Found realm "WiMax.com"
[suffix] Adding Stripped-User-Name =
"{am=1}A3D22E436B0C31DAC3639DCE50CB7B1E"
[suffix] Adding Realm = "WiMax.com"
[suffix] Authentication realm is LOCAL.
++[suffix] returns ok
[eap] EAP packet type response id 3 length 88
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/ttls
[eap] processing type ttls
[ttls] Authenticate
[ttls] processing EAP-TLS
  TLS Length 78
[ttls] Length Included
[ttls] eaptls_verify returned 11
[ttls]     (other): before/accept initialization
[ttls]     TLS_accept: before/accept initialization
[ttls] <<< TLS 1.0 Handshake [length 0049], ClientHello
[ttls]     TLS_accept: SSLv3 read client hello A
[ttls] >>> TLS 1.0 Handshake [length 002a], ServerHello
[ttls]     TLS_accept: SSLv3 write server hello A
[ttls] >>> TLS 1.0 Handshake [length 085e], Certificate
[ttls]     TLS_accept: SSLv3 write certificate A
[ttls] >>> TLS 1.0 Handshake [length 020d], ServerKeyExchange
[ttls]     TLS_accept: SSLv3 write key exchange A
[ttls] >>> TLS 1.0 Handshake [length 0004], ServerHelloDone
[ttls]     TLS_accept: SSLv3 write server done A
[ttls]     TLS_accept: SSLv3 flush data
[ttls]     TLS_accept: Need to read more data: SSLv3 read client certificate
A
In SSL Handshake Phase
In SSL Accept mode
[ttls] eaptls_process returned 13
++[eap] returns handled
Sending Access-Challenge of id 144 to 172.16.4.2 port 1812
        EAP-Message =
0x0104040015c000000aad160301002a0200002603014cbf28b84a7f4d6ff4170b1f0db6e02e
af9c2a9cb901ffea97b71698025d1c2500003900160301085e0b00085a0008570003a6308203
a23082028aa003020102020101300d06092a864886f70d0101040500308193310b3009060355
040613024652310f300d060355040813065261646975733112301006035504071309536f6d65
776865726531153013060355040a130c4578616d706c6520496e632e3120301e06092a864886
f70d010901161161646d696e406578616d706c652e636f6d312630240603550403131d457861
6d706c6520436572746966696361746520417574686f72697479
        EAP-Message =
0x301e170d3130303632313139303034345a170d3131303632313139303034345a307c310b30
09060355040613024652310f300d0603550408130652616469757331153013060355040a130c
4578616d706c6520496e632e312330210603550403131a4578616d706c652053657276657220
43657274696669636174653120301e06092a864886f70d010901161161646d696e406578616d
706c652e636f6d30820122300d06092a864886f70d01010105000382010f003082010a028201
0100a22c435dd3157a79c141fdc1a3ee89f7661a09187b958a5816beff7591e4b6aa37f7f256
cb182fffd65c4000a1498020aea03360223fad98df86a01d7b3c
        EAP-Message =
0xea1055ffdadbf60a2ea1b7af5a728cb75ec7e06ee90c39a9d6b1bdef454343d51c4f489be8
d3e17f545a9e8b7ac612dba36cf14c1a7709651d1bf04a057c4188fecee0dd6d80b9d5cca836
5e3e0aeccf0deef1f7516cce7d30fbe1271f8fcb25be192fbaf623340024debf13487225fead
75a4e557f21cb9707d519d2ad8de57eeda2c8b6afc7fc2b0e1a890fec212c80455a83a8b41bb
b35fc6420b167139c6033757b38124c971da04bd1c6da985c65077f55bee5b37c65e1f8cefa3
25c1672bff0203010001a317301530130603551d25040c300a06082b06010505070301300d06
092a864886f70d01010405000382010100c21ae0152cdbce17a1
        EAP-Message =
0x55233bf585be76ec2a3265e3e6ee7132890dc68d37c1864b08ba53f34c358953c528f8ab14
4716d17ebcd4f1b86f53522ce118b1a8932dfe4e3234137e94aecc3737c66d07405c9c369d2a
04f4d11c96685996d95313a35fde3b433d15eb93c915814fca156b6c5fcff010968ef7613142
d4cd95da673bdc1217739a88f8d43bb6ca26bee37a64f8ce1b50ec1b8e7c11c5291c88b5ebea
2e766bc31139fc03482232660ea54c22273996250eab67b9198b4ad378c5e1635162ffc5e382
bf5d60dd149e6c1b9f05eb5e94824b103f77e6e5875f6f8beeb48302defec698296f20c9ba78
9341834806deb515116aedc41d90bfebfaf0bea20004ab308204
        EAP-Message = 0xa73082038fa0030201020209
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x5176890253729ceb6482bebd55b3e66d
Finished request 3.
Going to the next request
Waking up in 4.8 seconds.
rad_recv: Access-Request packet from host 172.16.4.2 port 1812, id=145,
length=223
        User-Name = "{am=1}A3D22E436B0C31DAC3639DCE50CB7B1E at WiMax.com"
        EAP-Message = 0x020400061500
        Message-Authenticator = 0x5d4052f0ed761d8a9cf2b3e0ddd853ce
        NAS-Identifier = "Freeradius"
        NAS-IP-Address = 172.16.4.2
        Calling-Station-Id = "00-A0-0A-13-13-72"
        WiMAX-BS-Id = 0x000002010203
        NAS-Port-Type = 27
        Framed-MTU = 2000
        Service-Type = Framed-User
        WiMAX-GMT-Timezone-offset = 0
        WiMAX-Release = "1.0"
        WiMAX-Accounting-Capabilities = IP-Session-Based
        WiMAX-Hotlining-Capabilities = Hotline-Profile-Id
        WiMAX-Attr-1793 = 0x0000028a
        State = 0x5176890253729ceb6482bebd55b3e66d
+- entering group authorize {...}
++[preprocess] returns ok
++[mschap] returns noop
++[wimax] returns ok
[suffix] Looking up realm "WiMax.com" for User-Name =
"{am=1}A3D22E436B0C31DAC3639DCE50CB7B1E at WiMax.com"
[suffix] Found realm "WiMax.com"
[suffix] Adding Stripped-User-Name =
"{am=1}A3D22E436B0C31DAC3639DCE50CB7B1E"
[suffix] Adding Realm = "WiMax.com"
[suffix] Authentication realm is LOCAL.
++[suffix] returns ok
[eap] EAP packet type response id 4 length 6
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/ttls
[eap] processing type ttls
[ttls] Authenticate
[ttls] processing EAP-TLS
[ttls] Received TLS ACK
[ttls] ACK handshake fragment handler
[ttls] eaptls_verify returned 1
[ttls] eaptls_process returned 13
++[eap] returns handled
Sending Access-Challenge of id 145 to 172.16.4.2 port 1812
        EAP-Message =
0x0105040015c000000aad00b7ca1f4a75b65c48300d06092a864886f70d0101050500308193
310b3009060355040613024652310f300d060355040813065261646975733112301006035504
071309536f6d65776865726531153013060355040a130c4578616d706c6520496e632e312030
1e06092a864886f70d010901161161646d696e406578616d706c652e636f6d31263024060355
0403131d4578616d706c6520436572746966696361746520417574686f72697479301e170d31
30303632313139303034345a170d3131303632313139303034345a308193310b300906035504
0613024652310f300d0603550408130652616469757331123010
        EAP-Message =
0x06035504071309536f6d65776865726531153013060355040a130c4578616d706c6520496e
632e3120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d3126
30240603550403131d4578616d706c6520436572746966696361746520417574686f72697479
30820122300d06092a864886f70d01010105000382010f003082010a0282010100e3290705c4
fbb8ba17c01180a24b51b68fd9807e4a28e561d5d344b2baf607eda92d77219aa57c54c52b8b
d9a1f00f4d4e63f193d3089c1a396bc81a9fc88206480dc4a57b5b488fb34e9ac384ce919b94
567443f6fe9eb3199ef1cfec5cf3343d1003de5a824a6b4ff7ae
        EAP-Message =
0x783711920d724d0c6d8215edc2c8106d2d5bdb5c0db3438661f24fa3325a92e0959ca3b202
333824e1799e966f487857983c73b9477548cc8430cb1d94afb8751ace106e5401388bb34457
7f99fa44d7daa1e3b429f24bcdfd74c26813fbb390a65854d14ce5b3f9a8a06830f6deea9271
b7f09a8f2786d0bda65dad5733155c3028f318317133f2fdaa4c8687ab457f4cc9f6d1f90203
010001a381fb3081f8301d0603551d0e04160414c653e0f09e4775e74119ec9d2ca877eea7d7
857c3081c80603551d230481c03081bd8014c653e0f09e4775e74119ec9d2ca877eea7d7857c
a18199a48196308193310b3009060355040613024652310f300d
        EAP-Message =
0x060355040813065261646975733112301006035504071309536f6d65776865726531153013
060355040a130c4578616d706c6520496e632e3120301e06092a864886f70d01090116116164
6d696e406578616d706c652e636f6d312630240603550403131d4578616d706c652043657274
6966696361746520417574686f72697479820900b7ca1f4a75b65c48300c0603551d13040530
030101ff300d06092a864886f70d0101050500038201010054813204c14a1e24209f2775a069
ec1ef24c75af5aeae0cd8fd867228eb1053d085cb7a41f825bef7c00509b6c16f5418140dd84
d04a6470f0066b95863ebdd930d7137d4b269a127b5ac5d8bb54
        EAP-Message = 0xa450a87daa867321e3c885c3
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x5176890252739ceb6482bebd55b3e66d
Finished request 4.
Going to the next request
Waking up in 4.7 seconds.
rad_recv: Access-Request packet from host 172.16.4.2 port 1812, id=146,
length=223
        User-Name = "{am=1}A3D22E436B0C31DAC3639DCE50CB7B1E at WiMax.com"
        EAP-Message = 0x020500061500
        Message-Authenticator = 0xb01b4f195810b67967253ba37ea524b7
        NAS-Identifier = "Freeradius"
        NAS-IP-Address = 172.16.4.2
        Calling-Station-Id = "00-A0-0A-13-13-72"
        WiMAX-BS-Id = 0x000002010203
        NAS-Port-Type = 27
        Framed-MTU = 2000
        Service-Type = Framed-User
        WiMAX-GMT-Timezone-offset = 0
        WiMAX-Release = "1.0"
        WiMAX-Accounting-Capabilities = IP-Session-Based
        WiMAX-Hotlining-Capabilities = Hotline-Profile-Id
        WiMAX-Attr-1793 = 0x0000028a
        State = 0x5176890252739ceb6482bebd55b3e66d
+- entering group authorize {...}
++[preprocess] returns ok
++[mschap] returns noop
++[wimax] returns ok
[suffix] Looking up realm "WiMax.com" for User-Name =
"{am=1}A3D22E436B0C31DAC3639DCE50CB7B1E at WiMax.com"
[suffix] Found realm "WiMax.com"
[suffix] Adding Stripped-User-Name =
"{am=1}A3D22E436B0C31DAC3639DCE50CB7B1E"
[suffix] Adding Realm = "WiMax.com"
[suffix] Authentication realm is LOCAL.
++[suffix] returns ok
[eap] EAP packet type response id 5 length 6
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/ttls
[eap] processing type ttls
[ttls] Authenticate
[ttls] processing EAP-TLS
[ttls] Received TLS ACK
[ttls] ACK handshake fragment handler
[ttls] eaptls_verify returned 1
[ttls] eaptls_process returned 13
++[eap] returns handled
Sending Access-Challenge of id 146 to 172.16.4.2 port 1812
        EAP-Message =
0x010602cb158000000aad9c453583b6807402da0b0d8c90c139a9a0ddef70b01c5fa9ee8ac5
1255bf935d536f69d45b60a86ca871ddfc2c67c15cd531a3fae5cf5dfccf9170560759968f21
e6020052bf6baeb29ebcd3e174c16a36a30ef060c4d110b63cea4f16a115717fa6a8ba515021
0f86dd7f31bde3a3c35117d3d0b991763b97041453c7aa22a068e26a3b931dddbc429d8bdc75
66b6077f51717c612d206261f862b672cff53abfb016b9b839160301020d0c0002090080f5bd
24429f55049a0764bc935fbb95edf33bca4152a811bf1895e8dbfebd93cebc81616f548086f0
fb025058c15c8cc5f35dad890892db51c300b8fd6b7ecd9001da
        EAP-Message =
0xbe526cba14255c8cec05d51acdc7c0aa97a19bf634ee550c72543d1d4927b0819129b99790
32cf1d098638b89741798e7e2c6854e368448190fa73d3b68b00010200807e81e24c1ae047d3
80990ed7c9162f401152889d037653c766f8e064ef8ecd265ee1ae14eb45ea2d439957b5a893
75215102a41f70cc49f8d10e3d2a05e409d7ca28c5b9413a5031ac6a61ea09835e2e25dca3eb
f77e60594ac502a065158cdfaf1e9f8365b7087ed6116a6d02ba9f8b6cd66d1eb3fbe6437054
e3fa43851dff01001c660e9c8c92fc613d3141ec1803aa54d563c9ac308ec34d0c4ea292c532
0c62c5e26a94a4e06e9a714e1ea45a7e70c2cdb7cda733578462
        EAP-Message =
0x616eb18e840e0978b436bcbff53b5354189ef60e2b04485820731e99644cf868e02de8acef
67efadda72ca042c7ac19e68dba5e1522fbc69f594995bb4eaf68ba2ff04d8370e14d9c825fa
404b90103a24031890a956eb35a468b960ef805bb7f9f114ce70b9ed1a316e94cb6812f12474
175ae46ef86162e54ba3a5f7c79a13f4184c05f3d0da9babf87ef6af1c91b52ed9bc5a922733
56c47f6a4f1a3aaa72a2b869b805be022cc5bce65f053728810bf014d3a4bcaac7db665367a9
5b1444e1af622b4edbc5df16030100040e000000
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x5176890255709ceb6482bebd55b3e66d
Finished request 5.
Going to the next request
Waking up in 4.6 seconds.
rad_recv: Access-Request packet from host 172.16.4.2 port 1812, id=147,
length=425
        User-Name = "{am=1}A3D22E436B0C31DAC3639DCE50CB7B1E at WiMax.com"
        EAP-Message =
0x020600d01580000000c61603010086100000820080e4d7807abde242d95bf6c91a2fddf6cf
b57fe828e5df9422a9a8da9ef2cebb9b4645a06feb355df4b13f42ff5e57d7af163a7cffbf84
ba0f1881fcf7f19b527026980170237f9394a9432245cf5c7b522385045b63b6396d0a9b8be7
8908825dfbd6da5a1f0ea432332387160fc1cc5fd5aac8109782b0b30f939db9964cec5e1403
0100010116030100307cca567db3f81ef6a2685b75eeb16fb9aa012bd8d4f82fc4e73c026399
049ece7a5a8484487408ed2568af333cbbdb10
        Message-Authenticator = 0xedc54de4eb5ffc87ca17e9c9bc5d8619
        NAS-Identifier = "Freeradius"
        NAS-IP-Address = 172.16.4.2
        Calling-Station-Id = "00-A0-0A-13-13-72"
        WiMAX-BS-Id = 0x000002010203
        NAS-Port-Type = 27
        Framed-MTU = 2000
        Service-Type = Framed-User
        WiMAX-GMT-Timezone-offset = 0
        WiMAX-Release = "1.0"
        WiMAX-Accounting-Capabilities = IP-Session-Based
        WiMAX-Hotlining-Capabilities = Hotline-Profile-Id
        WiMAX-Attr-1793 = 0x0000028a
        State = 0x5176890255709ceb6482bebd55b3e66d
+- entering group authorize {...}
++[preprocess] returns ok
++[mschap] returns noop
++[wimax] returns ok
[suffix] Looking up realm "WiMax.com" for User-Name =
"{am=1}A3D22E436B0C31DAC3639DCE50CB7B1E at WiMax.com"
[suffix] Found realm "WiMax.com"
[suffix] Adding Stripped-User-Name =
"{am=1}A3D22E436B0C31DAC3639DCE50CB7B1E"
[suffix] Adding Realm = "WiMax.com"
[suffix] Authentication realm is LOCAL.
++[suffix] returns ok
[eap] EAP packet type response id 6 length 208
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/ttls
[eap] processing type ttls
[ttls] Authenticate
[ttls] processing EAP-TLS
  TLS Length 198
[ttls] Length Included
[ttls] eaptls_verify returned 11
[ttls] <<< TLS 1.0 Handshake [length 0086], ClientKeyExchange
[ttls]     TLS_accept: SSLv3 read client key exchange A
[ttls] <<< TLS 1.0 ChangeCipherSpec [length 0001]
[ttls] <<< TLS 1.0 Handshake [length 0010], Finished
[ttls]     TLS_accept: SSLv3 read finished A
[ttls] >>> TLS 1.0 ChangeCipherSpec [length 0001]
[ttls]     TLS_accept: SSLv3 write change cipher spec A
[ttls] >>> TLS 1.0 Handshake [length 0010], Finished
[ttls]     TLS_accept: SSLv3 write finished A
[ttls]     TLS_accept: SSLv3 flush data
[ttls]     (other): SSL negotiation finished successfully
SSL Connection Established
[ttls] eaptls_process returned 13
++[eap] returns handled
Sending Access-Challenge of id 147 to 172.16.4.2 port 1812
        EAP-Message =
0x0107004515800000003b14030100010116030100306b50179fa6a5874892188644af581c99
82c2b832ad254213ccdefa7fe910f8bac9e23cc3cd458bedf2b89c3fed673b0a
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x5176890254719ceb6482bebd55b3e66d
Finished request 6.
Going to the next request
Waking up in 3.3 seconds.
rad_recv: Access-Request packet from host 172.16.4.2 port 1812, id=148,
length=409
        User-Name = "{am=1}A3D22E436B0C31DAC3639DCE50CB7B1E at WiMax.com"
        EAP-Message =
0x020700c015001703010020a6ac1d7537f30019672dce1064fd2e338b680d4d58a74a47a5d7
544b1333cfdb1703010090a9c3a0e34fbc778490e986587c22b5709abb8cd73b778f28e40d3c
62af54f98b6e2f0fbcf505633e21afb5cb9bbe2f6920c64bfa1fd494ca3e54ecd2587fa9f03e
d91ebcb6f1ebe05eff8582d10d9c48aa1cd50a36ec10ba7aa8d2d0859742779e56ab4f75ebee
c3f45c8f186b0f113d5da41bb5d56be9d9d458663101dd212b1ec19851dadb19c6fdc6a77044
9ca909
        Message-Authenticator = 0xbb5e8ee22d928eea40ce4df5ad043ce6
        NAS-Identifier = "Freeradius"
        NAS-IP-Address = 172.16.4.2
        Calling-Station-Id = "00-A0-0A-13-13-72"
        WiMAX-BS-Id = 0x000002010203
        NAS-Port-Type = 27
        Framed-MTU = 2000
        Service-Type = Framed-User
        WiMAX-GMT-Timezone-offset = 0
        WiMAX-Release = "1.0"
        WiMAX-Accounting-Capabilities = IP-Session-Based
        WiMAX-Hotlining-Capabilities = Hotline-Profile-Id
        WiMAX-Attr-1793 = 0x0000028a
        State = 0x5176890254719ceb6482bebd55b3e66d
+- entering group authorize {...}
++[preprocess] returns ok
++[mschap] returns noop
++[wimax] returns ok
[suffix] Looking up realm "WiMax.com" for User-Name =
"{am=1}A3D22E436B0C31DAC3639DCE50CB7B1E at WiMax.com"
[suffix] Found realm "WiMax.com"
[suffix] Adding Stripped-User-Name =
"{am=1}A3D22E436B0C31DAC3639DCE50CB7B1E"
[suffix] Adding Realm = "WiMax.com"
[suffix] Authentication realm is LOCAL.
++[suffix] returns ok
[eap] EAP packet type response id 7 length 192
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/ttls
[eap] processing type ttls
[ttls] Authenticate
[ttls] processing EAP-TLS
[ttls] eaptls_verify returned 7
[ttls] Done initial handshake
[ttls] eaptls_process returned 7
[ttls] Session established.  Proceeding to decode tunneled attributes.
[ttls] Got tunneled request
        User-Name = "Silver2 at WiMax.com"
        MS-CHAP-Challenge = 0x4accd64250fe20627d27bedcc0281bc4
        MS-CHAP2-Response =
0x6a004accd64250fe20627d27bedcc0281bc40000000000000000a95f7c15e711eb1f6d0bd7
6b0bac132ed1be63f0faaf8ca7
        FreeRADIUS-Proxied-To = 127.0.0.1
[ttls] Sending tunneled request
        User-Name = "Silver2 at WiMax.com"
        MS-CHAP-Challenge = 0x4accd64250fe20627d27bedcc0281bc4
        MS-CHAP2-Response =
0x6a004accd64250fe20627d27bedcc0281bc40000000000000000a95f7c15e711eb1f6d0bd7
6b0bac132ed1be63f0faaf8ca7
        FreeRADIUS-Proxied-To = 127.0.0.1
        NAS-Identifier = "Freeradius"
        NAS-IP-Address = 172.16.4.2
        Calling-Station-Id = "00-A0-0A-13-13-72"
        WiMAX-BS-Id = 0x000002010203
        NAS-Port-Type = 27
        Framed-MTU = 2000
        Service-Type = Framed-User
        WiMAX-GMT-Timezone-offset = 0
        WiMAX-Release = "1.0"
        WiMAX-Accounting-Capabilities = IP-Session-Based
        WiMAX-Hotlining-Capabilities = Hotline-Profile-Id
        WiMAX-Attr-1793 = 0x0000028a
server inner-tunnel {
+- entering group authorize {...}
++[chap] returns noop
[mschap] Found MS-CHAP attributes.  Setting 'Auth-Type  = mschap'
++[mschap] returns ok
[suffix] Looking up realm "WiMax.com" for User-Name = "Silver2 at WiMax.com"
[suffix] Found realm "WiMax.com"
[suffix] Adding Stripped-User-Name = "Silver2"
[suffix] Adding Realm = "WiMax.com"
[suffix] Authentication realm is LOCAL.
++[suffix] returns ok
++[control] returns ok
[eap] No EAP-Message, not doing EAP
++[eap] returns noop
++[files] returns noop
[sql]   expand: %{User-Name} -> Silver2 at WiMax.com
[sql] sql_set_user escaped user --> 'Silver2 at WiMax.com'
rlm_sql (sql): Reserving sql socket id: 2
[sql]   expand: SELECT id, username, attribute, value, op          FROM
radcheck          WHERE username = BINARY '%{SQL-User-Name}'          ORDER
BY id -> SELECT id, username, attribute, value, op          FROM radcheck
WHERE username = BINARY 'Silver2 at WiMax.com'          ORDER BY id
[sql] User found in radcheck table
[sql]   expand: SELECT id, username, attribute, value, op          FROM
radreply          WHERE username = BINARY '%{SQL-User-Name}'          ORDER
BY id -> SELECT id, username, attribute, value, op          FROM radreply
WHERE username = BINARY 'Silver2 at WiMax.com'          ORDER BY id
[sql]   expand: SELECT groupname          FROM radusergroup         WHERE
username = BINARY '%{SQL-User-Name}'          ORDER BY priority -> SELECT
groupname          FROM radusergroup         WHERE username = BINARY
'Silver2 at WiMax.com'          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 = '4M-Silver'           ORDER
BY id
[sql] User found in group 4M-Silver
[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 = '4M-Silver'           ORDER
BY id
rlm_sql (sql): Released sql socket id: 2
++[sql] returns ok
++[expiration] returns noop
++[logintime] returns noop
[pap] Found existing Auth-Type, not changing it.
++[pap] returns noop
WARNING: You set Proxy-To-Realm = LOCAL, but the realm does not exist!
Cancelling invalid proxy request.
Found Auth-Type = MSCHAP
+- entering group MS-CHAP {...}
[mschap] Told to do MS-CHAPv2 for Silver2 at WiMax.com with NT-Password
[mschap] adding MS-CHAPv2 MPPE keys
++[mschap] returns ok
+- entering group post-auth {...}
[sql]   expand: %{User-Name} -> Silver2 at WiMax.com
[sql] sql_set_user escaped user --> 'Silver2 at WiMax.com'
[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 (
'Silver2 at WiMax.com',                           '',
'Access-Accept', '2010-10-20 13:36:58')
rlm_sql (sql) in sql_postauth: query is INSERT INTO radpostauth
(username, pass, reply, authdate)                           VALUES (
'Silver2 at WiMax.com',                           '',
'Access-Accept', '2010-10-20 13:36:58')
rlm_sql (sql): Reserving sql socket id: 1
rlm_sql (sql): Released sql socket id: 1
++[sql] returns ok
[sql_log] Processing sql_log_postauth
[sql_log]       expand: %{User-Name} -> Silver2 at WiMax.com
[sql_log]       expand: %{%{User-Name}:-DEFAULT} -> Silver2 at WiMax.com
[sql_log] sql_set_user escaped user --> 'Silver2 at WiMax.com'
[sql_log] WARNING: Deprecated conditional expansion ":-".  See "man unlang"
for details
[sql_log]       ... expanding second conditional
[sql_log]       expand: Chap-Password -> Chap-Password
[sql_log]       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
('Silver2 at WiMax.com', 'Chap-Password',                 'Access-Accept',
'2010-10-20 13:36:58');
[sql_log]       expand: /usr/local/var/log/radius/radacct/sql-relay ->
/usr/local/var/log/radius/radacct/sql-relay
++[sql_log] returns ok
} # server inner-tunnel
[ttls] Got tunneled reply code 2
        Framed-Filter-Id = "Silver"
        MS-CHAP2-Success =
0x6a533d46373730384443374231453134304131414141373331444432303831413142353245
324542344335
        MS-MPPE-Recv-Key = 0x168ef7c1d920df032a9fd2acf0f9b82f
        MS-MPPE-Send-Key = 0x86034a3ca1d92388aaf58f286a9c9e02
        MS-MPPE-Encryption-Policy = 0x00000001
        MS-MPPE-Encryption-Types = 0x00000006
[ttls] Got tunneled Access-Accept
[ttls] Got MS-CHAP2-Success, tunneling it to the client in a challenge.
++[eap] returns handled
Sending Access-Challenge of id 148 to 172.16.4.2 port 1812
        EAP-Message =
0x0108005f1580000000551703010050867c96689b4bd1574acd21f9891fa56511b9e18a9361
1d83afd8222dd04863417bf8cb57bd64ea5c7c66cb7be15247e290e85581bc1ef445dbf34f22
735c14695e5f72ad897b591bce22ad9cee638b9e
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x51768902577e9ceb6482bebd55b3e66d
Finished request 7.
Going to the next request
Waking up in 3.2 seconds.
rad_recv: Access-Request packet from host 172.16.4.2 port 1812, id=149,
length=223
        User-Name = "{am=1}A3D22E436B0C31DAC3639DCE50CB7B1E at WiMax.com"
        EAP-Message = 0x020800061500
        Message-Authenticator = 0x2006b33e2c36b0cd392c25f67988f668
        NAS-Identifier = "Freeradius"
        NAS-IP-Address = 172.16.4.2
        Calling-Station-Id = "00-A0-0A-13-13-72"
        WiMAX-BS-Id = 0x000002010203
        NAS-Port-Type = 27
        Framed-MTU = 2000
        Service-Type = Framed-User
        WiMAX-GMT-Timezone-offset = 0
        WiMAX-Release = "1.0"
        WiMAX-Accounting-Capabilities = IP-Session-Based
        WiMAX-Hotlining-Capabilities = Hotline-Profile-Id
        WiMAX-Attr-1793 = 0x0000028a
        State = 0x51768902577e9ceb6482bebd55b3e66d
+- entering group authorize {...}
++[preprocess] returns ok
++[mschap] returns noop
++[wimax] returns ok
[suffix] Looking up realm "WiMax.com" for User-Name =
"{am=1}A3D22E436B0C31DAC3639DCE50CB7B1E at WiMax.com"
[suffix] Found realm "WiMax.com"
[suffix] Adding Stripped-User-Name =
"{am=1}A3D22E436B0C31DAC3639DCE50CB7B1E"
[suffix] Adding Realm = "WiMax.com"
[suffix] Authentication realm is LOCAL.
++[suffix] returns ok
[eap] EAP packet type response id 8 length 6
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/ttls
[eap] processing type ttls
[ttls] Authenticate
[ttls] processing EAP-TLS
[ttls] Received TLS ACK
[ttls] ACK handshake is finished
[ttls] eaptls_verify returned 3
[ttls] eaptls_process returned 3
[eap] Freeing handler
++[eap] returns ok
+- entering group post-auth {...}
[sql]   expand: %{User-Name} ->
{am=1}A3D22E436B0C31DAC3639DCE50CB7B1E at WiMax.com
[sql] sql_set_user escaped user -->
'{am=1}A3D22E436B0C31DAC3639DCE50CB7B1E at WiMax.com'
[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 (
'=7Bam=3D1=7DA3D22E436B0C31DAC3639DCE50CB7B1E at WiMax.com',
'',                           'Access-Accept', '2010-10-20 13:36:58')
rlm_sql (sql) in sql_postauth: query is INSERT INTO radpostauth
(username, pass, reply, authdate)                           VALUES (
'=7Bam=3D1=7DA3D22E436B0C31DAC3639DCE50CB7B1E at WiMax.com',
'',                           'Access-Accept', '2010-10-20 13:36:58')
rlm_sql (sql): Reserving sql socket id: 0
rlm_sql (sql): Released sql socket id: 0
++[sql] returns ok
[sql_log] Processing sql_log_postauth
[sql_log]       expand: %{User-Name} ->
{am=1}A3D22E436B0C31DAC3639DCE50CB7B1E at WiMax.com
[sql_log]       expand: %{%{User-Name}:-DEFAULT} ->
{am=1}A3D22E436B0C31DAC3639DCE50CB7B1E at WiMax.com
[sql_log] sql_set_user escaped user -->
'{am=1}A3D22E436B0C31DAC3639DCE50CB7B1E at WiMax.com'
[sql_log] WARNING: Deprecated conditional expansion ":-".  See "man unlang"
for details
[sql_log]       ... expanding second conditional
[sql_log]       expand: Chap-Password -> Chap-Password
[sql_log]       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
('=7Bam=3D1=7DA3D22E436B0C31DAC3639DCE50CB7B1E at WiMax.com', 'Chap-Password',
'Access-Accept', '2010-10-20 13:36:58');
[sql_log]       expand: /usr/local/var/log/radius/radacct/sql-relay ->
/usr/local/var/log/radius/radacct/sql-relay
++[sql_log] returns ok
++[exec] returns noop
        expand: %{User-Name} ->
{am=1}A3D22E436B0C31DAC3639DCE50CB7B1E at WiMax.com
++[request] returns noop
        expand: %{User-Name} ->
{am=1}A3D22E436B0C31DAC3639DCE50CB7B1E at WiMax.com
        expand: %{EAP-MSK} ->
++[reply] returns noop
[wimax] MIP-RK =
0xc6fccac2e97b3d48060a81c368a9be35eeff4966da91a7026485ad67006af1912220236c32
d08bcb9c9d86d3aa2793cd058aea91ee6f3a2b8f9e7e0d4ea65eec
[wimax] MIP-SPI = abe5d10b
[wimax] WARNING: WiMAX-hHA-IP-MIP4 not found.  Cannot calculate MN-HA-CMIP4
key
++[wimax] returns updated
Sending Access-Accept of id 149 to 172.16.4.2 port 1812
        Framed-Filter-Id = "Silver"
        EAP-Message = 0x03080004
        Message-Authenticator = 0x00000000000000000000000000000000
        User-Name = "{am=1}A3D22E436B0C31DAC3639DCE50CB7B1E"
        WiMAX-IP-Technology = CMIP4
        WiMAX-FA-RK-Key = 0xc2d829f7e21967d6a9df3437f2b1edaeb88ef709
        WiMAX-MSK = 0x
        WiMAX-MSK =
0x428bcfef58b8d50a5abcadfc80973cae7183c5bda974c561acd123d542bfc603ea846fa1bb
869097e3dd267abe5cb343f0cf3ab587f65006a35784f925e2723e
        WiMAX-FA-RK-SPI = 198305195
Finished request 8.
Going to the next request
Waking up in 3.1 seconds.
Cleaning up request 1 ID 142 with timestamp +8
Cleaning up request 2 ID 143 with timestamp +8
Cleaning up request 3 ID 144 with timestamp +8
Cleaning up request 4 ID 145 with timestamp +8
Cleaning up request 5 ID 146 with timestamp +8
Waking up in 1.3 seconds.
Cleaning up request 6 ID 147 with timestamp +10
Waking up in 0.1 seconds.
Cleaning up request 7 ID 148 with timestamp +10
Cleaning up request 8 ID 149 with timestamp +10
Ready to process requests.

-----Original Message-----
From: Alan DeKok [mailto:aland at deployingradius.com] 
Sent: Wednesday, October 20, 2010 12:15 PM
To: David Peterson-WirelessConnections; FreeRadius users mailing list
Subject: Re: A tale of 2 WiMax NAS

David Peterson wrote:
> I have 2 NAS with different requirements in their WiMax handling.  One 
> requires me to have:
...
> Enabled in order to work and the other requires those commented out.  
> Is there a way to identify the NAS type to  elegantly have those properly
set?

  What is different between the requests that are sent by the two NAS
devices?

  Alan DeKok.




More information about the Freeradius-Users mailing list