PEAP/MSCHAPv2, Post-Auth-Type REJECT {} of inner-tunnel is neverentered for access reject
Fads Afds
down101load at yahoo.com.hk
Wed Jul 21 12:10:07 CEST 2010
Dear Fellows,
I tried to copy inner-tunnel control attribute to outer tunnel (i.e. default) using update in authorize {} of inner-tunnel. However, it still fail. The attribute value is still empty.
I think I have used wrong method of copy control attribute value from inner-tunnel to outer tunnel (i.e. default). Would you give me an example of how to copy the attribute from inner-tunnel to outer tunnel (i.e. default) so that I can access that value in Post-Auth-Type REJECT {} section of default using sql?
Thanks in advance.
After your reply, I include:
1. authorize {} section of inner-tunnel to copy control attribute from inner-tunnel to default
2. sql query for radpostauth
3. content of authorize section of file /etc/raddb/sites-available/default
4. radiusd -X debug message for access-reject case
------------Alan's reply ---------------------------------------
Fads Afds wrote:
> I tried to get the error-message of inner-tunnel by running sql query in "Post-Auth-Type Reject {} of default. The message field in radpostauth table is empty. The query seems cannot access %{inner.control:My-Err-Message} attribute.
> My question is: Can sql in default (outer session) access innner-server control attribute when the login is rejected? If the answer is no, would you hint me how I can get & log the error message of inner-session?
No, unfortunately not. *But* the "inner tunnel" server can copy them
from the inner to outer tunnel.
Alan DeKok.
-----------Alan's reply ends ------------------------------
-------------1. authorize {} section of inner-tunnel to copy control attribute from inner-tunnel to default -----------
authorize{
mschap
suffix
update control {
Proxy-To-Realm := LOCAL
}
eap {
ok = return
}
sql
if (!(control:Cleartext-Password)) {
update outer.control {
My-Err-Message := "Username %{request:User-Name} not existed in db"
Post-Auth-Type := "REJECT"
}
reject
}
........
}
-------------1. ends --------------------------
------2. sql query for radpostauth ------------------
postauth_query = "INSERT INTO ${postauth_table} \
(ID, username, password, nas_ip, auth_result, reply_message, authdate) \
VALUES (NULL, \
'%{User-Name}', \
aes_encrypt('NA', 'abc123456def'), \
'%{NAS-IP-ADDRESS}', \
'%{reply:Packet-Type}', \
'%{control:My-Err-Message}', \
'%S')"
-----------------2. ends -----------------------------
-----3. content of Post-Auth-Type Reject{} section of file /etc/raddb/sites-available/default ---------------
Post-Auth-Type REJECT {
sql
reply_log
attr_filter.access_reject
}
----3. ends ------------------------------------------
----4. radiusd -X message for rejected case------------------------------
Listening on authentication address * port 1812
Listening on accounting address * port 1813
Listening on authentication address 127.0.0.1 port 18120 as server inner-tunnel
Listening on proxy address * port 1814
Ready to process requests.
rad_recv: Access-Request packet from host 127.0.0.1 port 48700, id=0, length=118
User-Name = "time2"
NAS-IP-Address = 127.0.0.1
Calling-Station-Id = "02-00-00-00-00-01"
Framed-MTU = 1400
NAS-Port-Type = Wireless-802.11
Connect-Info = "CONNECT 11Mbps 802.11b"
EAP-Message = 0x0200000a0174696d6532
Message-Authenticator = 0xbf677b5406f4f2e4aaa8fdd622a90135
+- entering group authorize {...}
++[preprocess] returns ok
++[mschap] returns noop
[suffix] No '@' in User-Name = "time2", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 0 length 10
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
[pap] WARNING! No "known good" password found for the user. Authentication may
fail because of this.
++[pap] returns noop
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] EAP Identity
[eap] processing type tls
[tls] Flushing SSL sessions (of #0)
[tls] Initiate
[tls] Start returned 1
++[eap] returns handled
Sending Access-Challenge of id 0 to 127.0.0.1 port 48700
EAP-Message = 0x010100061920
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xc6f6f2e2c6f7eb894ef48dfece99fe9b
Finished request 0.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 127.0.0.1 port 48700, id=1, length=235
User-Name = "time2"
NAS-IP-Address = 127.0.0.1
Calling-Station-Id = "02-00-00-00-00-01"
Framed-MTU = 1400
NAS-Port-Type = Wireless-802.11
Connect-Info = "CONNECT 11Mbps 802.11b"
EAP-Message = 0x0201006d198000000063160301005e0100005a03014c46c6d409d37d
448568c6b9949492292a7794eff0dd6166992839432da8b297000032003900380035008800870084
00160013000a00330032002f00450044004100050004001500120009001400110008000600030201
00
State = 0xc6f6f2e2c6f7eb894ef48dfece99fe9b
Message-Authenticator = 0xc5a15c107e27de2e71efdf138e549b55
+- entering group authorize {...}
++[preprocess] returns ok
++[mschap] returns noop
[suffix] No '@' in User-Name = "time2", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 1 length 109
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/peap
[eap] processing type peap
[peap] processing EAP-TLS
TLS Length 99
[peap] Length Included
[peap] eaptls_verify returned 11
[peap] (other): before/accept initialization
[peap] TLS_accept: before/accept initialization
[peap] <<< TLS 1.0 Handshake [length 005e], ClientHello
[peap] TLS_accept: SSLv3 read client hello A
[peap] >>> TLS 1.0 Handshake [length 004a], ServerHello
[peap] TLS_accept: SSLv3 write server hello A
[peap] >>> TLS 1.0 Handshake [length 084d], Certificate
[peap] TLS_accept: SSLv3 write certificate A
[peap] >>> TLS 1.0 Handshake [length 020d], ServerKeyExchange
[peap] TLS_accept: SSLv3 write key exchange A
[peap] >>> TLS 1.0 Handshake [length 0004], ServerHelloDone
[peap] TLS_accept: SSLv3 write server done A
[peap] TLS_accept: SSLv3 flush data
[peap] TLS_accept: Need to read more data: SSLv3 read client certificate A
In SSL Handshake Phase
In SSL Accept mode
[peap] eaptls_process returned 13
[peap] EAPTLS_HANDLED
++[eap] returns handled
Sending Access-Challenge of id 1 to 127.0.0.1 port 48700
EAP-Message = 0x0102040019c000000abc160301004a0200004603014c46c6d4c2384f
6b84afa69e698e9b20c99898d475aa86abee41e2fa89040310204387d2f0346c9170879501ac2448
3af389a0b701d29af0eb17a03ca2e96f983a003901160301084d0b0008490008460003a8308203a4
3082028ca003020102020101300d06092a864886f70d010104050030818c310b3009060355040613
02434e310b300906035504081302484b310c300a06035504071303656475310d300b060355040a13
04484b42553127302506092a864886f70d0109011618726f6f7440667267756573742e686b62752e
6564752e686b312a302806035504031321484b425520477565
EAP-Message = 0x73742043412063657274202836346269742073657276657229302017
0d3130303632343033353835305a180f32303530303631343033353835305a308182310b30090603
5504061302434e310b300906035504081302484b310d300b060355040a1304484b4255312e302c06
035504031325484b4255204775657374207365727665722063657274696669636174652028363462
6974293127302506092a864886f70d0109011618726f6f7440667267756573742e686b62752e6564
752e686b30820122300d06092a864886f70d01010105000382010f003082010a0282010100c7649e
e337738ce465aec9a12a375bd4d76fc3c2f50ac701065d1433
EAP-Message = 0x22c38dd78776d5ad0cb747a32f6b512dce6d26cccffefd49cf151767
0305c6cb6eee0b70c86cb259383ca439bf011e8d8689cd17c41e99498256f13e6f14282b8eeef46f
95e742d40254b69d7270d1d349e8cd41cff1dc98ea38fb494ea6007aed1575391d69e9f1c230fea9
125f09a28d544282e9520e4c5987f54ff43f94567991d6172f98bfd3a200aeb07e60345e40caff2f
1f34c52e77707e3321a774bc7601827ccbd723e044ee635de38dc174e37aea2640f5dbacb3454bd8
9bd2e03b81031365232fe8f014c069983950f75aa8fdcce7a9ee52d57dc7fec1512a57fabb3b993b
0203010001a317301530130603551d25040c300a06082b0601
EAP-Message = 0x0505070301300d06092a864886f70d01010405000382010100192613
ffaf84004131ad7ce0d3da7b42d8a594371b96058ea7dc28554921dfd279076ad03cbf83ab81d7d3
ac909202e97a3c22fdad6eee38f2961ef4e9cc9398c5e4bd8a0f41c9174d4fa44a1e77e95c887c06
5197300ea90c8ffc1d32c898c4e137b6a74834c769d7be8008fea4b3ca9c5a33505b588fd93fa440
584d00f8c0c11d62bd886037289e5f27cec1039a4c311a04a7cf75b9ed578b840c66993dea65d31a
df591ffc290d98d6565e70a1d3d45ae3f0c877c5104d1def8c23a79f38c92731165bfb2a84759f2c
6c07e15ff75e4fe6f99e67dac4fc5ca7bf6cbdf849c44b77f6
EAP-Message = 0x614977256b1dcde1b92a76f3
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xc6f6f2e2c7f4eb894ef48dfece99fe9b
Finished request 1.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 127.0.0.1 port 48700, id=2, length=132
User-Name = "time2"
NAS-IP-Address = 127.0.0.1
Calling-Station-Id = "02-00-00-00-00-01"
Framed-MTU = 1400
NAS-Port-Type = Wireless-802.11
Connect-Info = "CONNECT 11Mbps 802.11b"
EAP-Message = 0x020200061900
State = 0xc6f6f2e2c7f4eb894ef48dfece99fe9b
Message-Authenticator = 0x4ff1c2811b89fc72d1647ce0b8d2421a
+- entering group authorize {...}
++[preprocess] returns ok
++[mschap] returns noop
[suffix] No '@' in User-Name = "time2", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 2 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/peap
[eap] processing type peap
[peap] processing EAP-TLS
[peap] Received TLS ACK
[peap] ACK handshake fragment handler
[peap] eaptls_verify returned 1
[peap] eaptls_process returned 13
[peap] EAPTLS_HANDLED
++[eap] returns handled
Sending Access-Challenge of id 2 to 127.0.0.1 port 48700
EAP-Message = 0x010303fc1940d8d084a884e20a2a165c46af33618c22000498308204
943082037ca003020102020900a00b0c8b6ee723bb300d06092a864886f70d010105050030818c31
0b300906035504061302434e310b300906035504081302484b310c300a0603550407130365647531
0d300b060355040a1304484b42553127302506092a864886f70d0109011618726f6f744066726775
6573742e686b62752e6564752e686b312a302806035504031321484b425520477565737420434120
636572742028363462697420736572766572293020170d3130303632343033353833335a180f3230
3530303631343033353833335a30818c310b30090603550406
EAP-Message = 0x1302434e310b300906035504081302484b310c300a06035504071303
656475310d300b060355040a1304484b42553127302506092a864886f70d0109011618726f6f7440
667267756573742e686b62752e6564752e686b312a302806035504031321484b4255204775657374
204341206365727420283634626974207365727665722930820122300d06092a864886f70d010101
05000382010f003082010a0282010100c001917da3c962085a616702fa98c2bd794c7edfa3a1f038
258e018a126e736e3a61ae5120b956ab0566a9258b889d66e616e2d702b1a0f5ec79b1b484a9a9ec
5ff3ba49d31895a6073ac132c9aa28f3e9906d0a6e3c24e852
EAP-Message = 0x621586b8db41ce111ebf2befc143a5cc9d562d020594fe407135ec1c
068dd0303eca75e5c5dd9cab898af3e870072ea3eca78602644eea0bac0c5619925b56aba1b1c1fc
4c48fded87cdcf44d1b99a2c1f534e8b88e4a35f9d1ffa8a50cdb402743516a0cbce2a4796459501
875ec225357d4a362202e15ee12a0154f018e5b84a5e5884c268d3154ed41f7b78ea2f6df852e07b
dd50a55c26467bcaf75c41d393bc78b27fb5170203010001a381f43081f1301d0603551d0e041604
14c134ca58d9d8f09b9207417630a08266b192ef523081c10603551d230481b93081b68014c134ca
58d9d8f09b9207417630a08266b192ef52a18192a4818f3081
EAP-Message = 0x8c310b300906035504061302434e310b300906035504081302484b31
0c300a06035504071303656475310d300b060355040a1304484b42553127302506092a864886f70d
0109011618726f6f7440667267756573742e686b62752e6564752e686b312a302806035504031321
484b42552047756573742043412063657274202836346269742073657276657229820900a00b0c8b
6ee723bb300c0603551d13040530030101ff300d06092a864886f70d010105050003820101000d81
bb75569e9ce10ee1cc274ce224d6d175d681f14079bdb2953b179dc9e15eedecd08f8d61f1759f3b
b4c97458573e0b9b6b6be66954fc48d713a54ad949e99d806a
EAP-Message = 0x400957b5cd394c74
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xc6f6f2e2c4f5eb894ef48dfece99fe9b
Finished request 2.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 127.0.0.1 port 48700, id=3, length=132
User-Name = "time2"
NAS-IP-Address = 127.0.0.1
Calling-Station-Id = "02-00-00-00-00-01"
Framed-MTU = 1400
NAS-Port-Type = Wireless-802.11
Connect-Info = "CONNECT 11Mbps 802.11b"
EAP-Message = 0x020300061900
State = 0xc6f6f2e2c4f5eb894ef48dfece99fe9b
Message-Authenticator = 0xde14f263c2c7416dc6e76fe8790561f0
+- entering group authorize {...}
++[preprocess] returns ok
++[mschap] returns noop
[suffix] No '@' in User-Name = "time2", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 3 length 6
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/peap
[eap] processing type peap
[peap] processing EAP-TLS
[peap] Received TLS ACK
[peap] ACK handshake fragment handler
[peap] eaptls_verify returned 1
[peap] eaptls_process returned 13
[peap] EAPTLS_HANDLED
++[eap] returns handled
Sending Access-Challenge of id 3 to 127.0.0.1 port 48700
EAP-Message = 0x010402d6190012c062cd3163799ab42c262a3b39ee4aadeba8ca0584
510b5f850ecbe4afc188b998b5b79ebc112998a4791842e212835761d44b5202634a16bdc8886be5
a2a6ddef1becbbaa64117a58fd73726f412c140197da3a29fc44aa1b67361c18f9f72312826067f6
4edc638e6a8b5511cd2c9eff129e700e0d88cb6de9ef5c6c909025dc37b4abdc9fdc643561bb06b1
e07e30de728a7e8a4dc07dda92896b8975d7907b85b66fedf2623b70b61a7757012cb421a8c76616
0301020d0c00020900808fcc5daaf65ec4b9ed53a13aa5563c3a857d7b01a0935ce18302cbbd8117
bdcee617438d810d33e6737c2b63ad1b1e728d85e9aa9c155d
EAP-Message = 0x84c5499240de4a0574ca81181dd71a196f1dccceee978f8380d16b7e
6019d903f2d5ed2428b8649b958dbd4a5c52b8f99989c064eb651266552a0b7eab32727454b2eee7
89c78aee3b000102008084956c57a4a4b141554f2c86380c3f57fec3e34f8088703c2413a397374c
f9431f25f4679341df14aec581da079636e09df48d3db90e91c660f93d90c8d8e1f0fe1ae32a2e4e
1e1ad215d59f5b6572dc9adf243cbd19227ea6f225c136065861f039bfde75f0d95e5275c6beb2d8
c7179aa173a8924a34a4796a106befd300e301007caa0de5898f20a777fcce5ba0db9d58bace9248
e9ce9ba09cba932b1211d99b8b61adb7855639a5488d697384
EAP-Message = 0x7f8cc48dfcdfc8b9e6388c07f12c0a45e41970ea85b0a7cbc3c2bdb2
c3046a866a923b4f775d0de4d30479d7540b541f56165210868611b0059298560b7f96353be1997a
24b6a952df65c72a1ef9486dc0d01b6c27aa746f03987035a881a7712ca6a51a5df2922b85f5705d
c9df28a9c6eaa78eedc4f06eaa695ebf7b2320915dffd6b9dfb482f6854450caf7d25a259bbba459
090921be037eede2969271895b48ad7ffd2da5f32c3b788e08b6b818071d4dd87c1372f17316c7ff
a41014fca5e72c763052be8315ddb965775e63f871fc3e16030100040e000000
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xc6f6f2e2c5f2eb894ef48dfece99fe9b
Finished request 3.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 127.0.0.1 port 48700, id=4, length=334
User-Name = "time2"
NAS-IP-Address = 127.0.0.1
Calling-Station-Id = "02-00-00-00-00-01"
Framed-MTU = 1400
NAS-Port-Type = Wireless-802.11
Connect-Info = "CONNECT 11Mbps 802.11b"
EAP-Message = 0x020400d01980000000c61603010086100000820080836b607053d520
2b0e9a082661805bfd4efcd151dadc769209b259fb5f655e3e2add8e777afb53d4ef0fb317d06595
0cce5a1d51bec91f36b0abf776241812264c62ba6bd05d460e584ae18f6dc5dca8a113e0d192d506
5521e785314d8ebbaeece1eb8270fb236e95d66bd448050ccad4fbecde9cdd64cbed8c1dd64ff7bd
6114030100010116030100301d6b888f742b258994cff559a60927f34ca3963e68c1a9e8171f89c6
950e075722bbf60d7ca9c95c74f5d97b489f4b5c
State = 0xc6f6f2e2c5f2eb894ef48dfece99fe9b
Message-Authenticator = 0x7fd003ee51ed5a56b66b51463e5447c7
+- entering group authorize {...}
++[preprocess] returns ok
++[mschap] returns noop
[suffix] No '@' in User-Name = "time2", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 4 length 208
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/peap
[eap] processing type peap
[peap] processing EAP-TLS
TLS Length 198
[peap] Length Included
[peap] eaptls_verify returned 11
[peap] <<< TLS 1.0 Handshake [length 0086], ClientKeyExchange
[peap] TLS_accept: SSLv3 read client key exchange A
[peap] <<< TLS 1.0 ChangeCipherSpec [length 0001]
[peap] <<< TLS 1.0 Handshake [length 0010], Finished
[peap] TLS_accept: SSLv3 read finished A
[peap] >>> TLS 1.0 ChangeCipherSpec [length 0001]
[peap] TLS_accept: SSLv3 write change cipher spec A
[peap] >>> TLS 1.0 Handshake [length 0010], Finished
[peap] TLS_accept: SSLv3 write finished A
[peap] TLS_accept: SSLv3 flush data
SSL: adding session 4387d2f0346c9170879501ac24483af389a0b701d29af0eb17a03ca2e9
6f983a to cache
[peap] (other): SSL negotiation finished successfully
SSL Connection Established
[peap] eaptls_process returned 13
[peap] EAPTLS_HANDLED
++[eap] returns handled
Sending Access-Challenge of id 4 to 127.0.0.1 port 48700
EAP-Message = 0x0105004119001403010001011603010030e6a153c430183fb786c452
5c7cbfc7c125546b1244a9f8fed714e6be7eff0e26ee8fb143158876317d8073de8a7847b5
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xc6f6f2e2c2f3eb894ef48dfece99fe9b
Finished request 4.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 127.0.0.1 port 48700, id=5, length=132
User-Name = "time2"
NAS-IP-Address = 127.0.0.1
Calling-Station-Id = "02-00-00-00-00-01"
Framed-MTU = 1400
NAS-Port-Type = Wireless-802.11
Connect-Info = "CONNECT 11Mbps 802.11b"
EAP-Message = 0x020500061900
State = 0xc6f6f2e2c2f3eb894ef48dfece99fe9b
Message-Authenticator = 0x5a5c79e12214769c5c4ca90b358d4f85
+- entering group authorize {...}
++[preprocess] returns ok
++[mschap] returns noop
[suffix] No '@' in User-Name = "time2", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 5 length 6
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/peap
[eap] processing type peap
[peap] processing EAP-TLS
[peap] Received TLS ACK
[peap] ACK handshake is finished
[peap] eaptls_verify returned 3
[peap] eaptls_process returned 3
[peap] EAPTLS_SUCCESS
++[eap] returns handled
Sending Access-Challenge of id 5 to 127.0.0.1 port 48700
EAP-Message = 0x0106002b19001703010020aec315f53e1e8847c53a4264738a8acbe3
f14d22ea7cd7500c99cb39f39296c5
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xc6f6f2e2c3f0eb894ef48dfece99fe9b
Finished request 5.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 127.0.0.1 port 48700, id=6, length=222
User-Name = "time2"
NAS-IP-Address = 127.0.0.1
Calling-Station-Id = "02-00-00-00-00-01"
Framed-MTU = 1400
NAS-Port-Type = Wireless-802.11
Connect-Info = "CONNECT 11Mbps 802.11b"
EAP-Message = 0x02060060190017030100203f6b5f574cbe7adebedea1dfaab8b98023
def490681f0ba0228cfd700d81a18f1703010030cd8923af00f93c5760b032e8160701a1add2fed2
692be5bb2f290544e1675c6a4ef7ac2dc1c27afbe1858a8b22d52bf6
State = 0xc6f6f2e2c3f0eb894ef48dfece99fe9b
Message-Authenticator = 0x6bd17dea90eb6f46972ccfc8f532a219
+- entering group authorize {...}
++[preprocess] returns ok
++[mschap] returns noop
[suffix] No '@' in User-Name = "time2", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 6 length 96
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/peap
[eap] processing type peap
[peap] processing EAP-TLS
[peap] eaptls_verify returned 7
[peap] Done initial handshake
[peap] eaptls_process returned 7
[peap] EAPTLS_OK
[peap] Session established. Decoding tunneled attributes.
[peap] Identity - time2
[peap] Got tunnled request
EAP-Message = 0x0206000a0174696d6532
server (null) {
PEAP: Got tunneled identity of time2
PEAP: Setting default EAP type for tunneled EAP session.
PEAP: Setting User-Name to time2
Sending tunneled request
EAP-Message = 0x0206000a0174696d6532
FreeRADIUS-Proxied-To = 127.0.0.1
User-Name = "time2"
NAS-IP-Address = 127.0.0.1
Calling-Station-Id = "02-00-00-00-00-01"
Framed-MTU = 1400
NAS-Port-Type = Wireless-802.11
Connect-Info = "CONNECT 11Mbps 802.11b"
server inner-tunnel {
+- entering group authorize {...}
++[mschap] returns noop
[suffix] No '@' in User-Name = "time2", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
++[control] returns noop
[eap] EAP packet type response id 6 length 10
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
[auth_log] expand: /var/log/radius/radacct/%{Client-IP-Address}/auth-detail
-%Y%m%d -> /var/log/radius/radacct/127.0.0.1/auth-detail-20100721
[auth_log] /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expan
ds to /var/log/radius/radacct/127.0.0.1/auth-detail-20100721
[auth_log] expand: %t -> Wed Jul 21 18:07:16 2010
++[auth_log] returns ok
[sql] expand: %{User-Name} -> time2
[sql] sql_set_user escaped user --> 'time2'
rlm_sql (sql): Reserving sql socket id: 4
[sql] expand: (SELECT id, username, attribute, value, op FROM radcheck WHERE
username = '%{SQL-User-Name}' and attribute != 'Cleartext-Password') UNION (SEL
ECT id, username, attribute, aes_decrypt(value,'abc123456def'), op FROM radcheck
WHERE username = '%{SQL-User-Name}' and attribute = 'Cleartext-Password') ORDER
BY id -> (SELECT id, username, attribute, value, op FROM radcheck WHERE usern
ame = 'time2' and attribute != 'Cleartext-Password') UNION (SELECT id, username,
attribute, aes_decrypt(value,'abc123456def'), op FROM radcheck WHERE username =
'time2' and attribute = 'Cleartext-Password') ORDER BY id
rlm_sql_mysql: query: (SELECT id, username, attribute, value, op FROM radcheck
WHERE username = 'time2' and attribute != 'Cleartext-Password') UNION (SELECT
id, username, attribute, aes_decrypt(value,'abc123456def'), op FROM radcheck WHE
RE username = 'time2' and attribute = 'Cleartext-Password') ORDER BY id
[sql] User found in radcheck table
[sql] expand: SELECT id, username, attribute, value, op FROM radrepl
y WHERE username = '%{SQL-User-Name}' ORDER BY id -> SELECT
id, username, attribute, value, op FROM radreply WHERE usern
ame = 'time2' ORDER BY id
rlm_sql_mysql: query: SELECT id, username, attribute, value, op FROM
radreply WHERE username = 'time2' ORDER BY id
[sql] expand: SELECT groupname FROM radusergroup WHERE user
name = '%{SQL-User-Name}' ORDER BY priority -> SELECT groupname
FROM radusergroup WHERE username = 'time2' ORDER BY prior
ity
rlm_sql_mysql: query: SELECT groupname FROM radusergroup WHE
RE username = 'time2' ORDER BY priority
rlm_sql (sql): Released sql socket id: 4
++[sql] returns ok
++? if (!(control:Cleartext-Password))
?? Evaluating (control:Cleartext-Password) -> TRUE
? Converting !TRUE -> FALSE
++? if (!(control:Cleartext-Password)) -> FALSE
++? elsif ((reply:acct_expiration) && ("%{reply:acct_expiration}" < "%D") )
?? Evaluating (reply:acct_expiration) -> TRUE
expand: %{reply:acct_expiration} -> 29991231
expand: %D -> 20100721
?? Evaluating ("%{reply:acct_expiration}" < "%D") -> FALSE
++? elsif ((reply:acct_expiration) && ("%{reply:acct_expiration}" < "%D") ) ->
FALSE
++? elsif ((reply:acct_expiration) && (reply:1st_login_date) && (reply:ticket_e
xpiration) && ("%{reply:1st_login_date}" != "29991231") && ("%{reply:ticket_expi
ration}" < "%D") )
?? Evaluating (reply:acct_expiration) -> TRUE
?? Evaluating (reply:1st_login_date) -> TRUE
?? Evaluating (reply:ticket_expiration) -> TRUE
expand: %{reply:1st_login_date} -> 20100619
?? Evaluating ("%{reply:1st_login_date}" != "29991231") -> TRUE
expand: %{reply:ticket_expiration} -> 20100917
expand: %D -> 20100721
?? Evaluating ("%{reply:ticket_expiration}" < "%D") -> FALSE
++? elsif ((reply:acct_expiration) && (reply:1st_login_date) && (reply:ticket_e
xpiration) && ("%{reply:1st_login_date}" != "29991231") && ("%{reply:ticket_expi
ration}" < "%D") ) -> FALSE
rlm_sqlcounter: Entering module authorize code
sqlcounter_expand: 'SELECT SUM(AcctSessionTime) FROM radacct WHERE UserName='%{
User-Name}''
[noreset_time_counter] expand: SELECT SUM(AcctSessionTime) FROM radacct WHERE U
serName='%{User-Name}' -> SELECT SUM(AcctSessionTime) FROM radacct WHERE UserNam
e='time2'
sqlcounter_expand: '%{sql:SELECT SUM(AcctSessionTime) FROM radacct WHERE UserNa
me='time2'}'
[noreset_time_counter] sql_xlat
[noreset_time_counter] expand: %{User-Name} -> time2
[noreset_time_counter] sql_set_user escaped user --> 'time2'
[noreset_time_counter] expand: SELECT SUM(AcctSessionTime) FROM radacct WHERE U
serName='time2' -> SELECT SUM(AcctSessionTime) FROM radacct WHERE UserName='time
2'
[noreset_time_counter] expand: /var/log/radius/sqltrace.sql -> /var/log/radius/
sqltrace.sql
rlm_sql (sql): Reserving sql socket id: 3
rlm_sql_mysql: query: SELECT SUM(AcctSessionTime) FROM radacct WHERE UserName='
time2'
[noreset_time_counter] sql_xlat finished
rlm_sql (sql): Released sql socket id: 3
[noreset_time_counter] expand: %{sql:SELECT SUM(AcctSessionTime) FROM radacct W
HERE UserName='time2'} -> 876
rlm_sqlcounter: (Check item - counter) is less than zero
rlm_sqlcounter: Rejected user time2, check_item=600, counter=876
++[noreset_time_counter] returns reject
++? if (reject)
? Evaluating (reject) -> TRUE
++? if (reject) -> TRUE
++- entering if (reject) {...}
+++[outer.control] returns reject
++- if (reject) returns reject
Invalid user (rlm_sqlcounter: Maximum never usage time reached): [time2/<via Aut
h-Type = EAP>] (from client localhost port 0 cli 02-00-00-00-00-01 via TLS tunne
l)
} # server inner-tunnel
[peap] Got tunneled reply code 3
1st_login_date := "20100619"
acct_expiration := "29991231"
ticket_days := "90"
ticket_expiration := "20100917"
Reply-Message = "Your maximum never usage time has been reached"
[peap] Got tunneled reply RADIUS code 3
1st_login_date := "20100619"
acct_expiration := "29991231"
ticket_days := "90"
ticket_expiration := "20100917"
Reply-Message = "Your maximum never usage time has been reached"
[peap] Tunneled authentication was rejected.
[peap] FAILURE
++[eap] returns handled
Sending Access-Challenge of id 6 to 127.0.0.1 port 48700
EAP-Message = 0x0107003b190017030100307c3d0849e67e324f5c4dc05f3057f29608
2f681afe3ea6afbbaf7401626f790dfdaf578b170dec9d10a8940db452bc56
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xc6f6f2e2c0f1eb894ef48dfece99fe9b
Finished request 6.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 127.0.0.1 port 48700, id=7, length=222
User-Name = "time2"
NAS-IP-Address = 127.0.0.1
Calling-Station-Id = "02-00-00-00-00-01"
Framed-MTU = 1400
NAS-Port-Type = Wireless-802.11
Connect-Info = "CONNECT 11Mbps 802.11b"
EAP-Message = 0x02070060190017030100205a84d4054297caf70cfd919519a7a826b6
aeccb463a63a6912dd35ac6c71be831703010030fa26f87fcfea5b33edf93ee1820f5f6ff3420ae7
1191726eac788bbc21d8d006e3d3b0f1ff130bb8bb32dd014ea83086
State = 0xc6f6f2e2c0f1eb894ef48dfece99fe9b
Message-Authenticator = 0xe1e536bac5897a5941106620a6ecdd33
+- entering group authorize {...}
++[preprocess] returns ok
++[mschap] returns noop
[suffix] No '@' in User-Name = "time2", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 7 length 96
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/peap
[eap] processing type peap
[peap] processing EAP-TLS
[peap] eaptls_verify returned 7
[peap] Done initial handshake
[peap] eaptls_process returned 7
[peap] EAPTLS_OK
[peap] Session established. Decoding tunneled attributes.
[peap] Received EAP-TLV response.
[peap] Had sent TLV failure. User was rejected earlier in this session.
SSL: Removing session 4387d2f0346c9170879501ac24483af389a0b701d29af0eb17a03ca2
e96f983a from the cache
[eap] Handler failed in EAP/peap
[eap] Failed in EAP select
++[eap] returns invalid
Failed to authenticate the user.
Login incorrect: [time2/<via Auth-Type = EAP>] (from client localhost port 0 cli
02-00-00-00-00-01)
Using Post-Auth-Type Reject
+- entering group REJECT {...}
[sql] expand: %{User-Name} -> time2
[sql] sql_set_user escaped user --> 'time2'
[sql] expand: INSERT INTO radpostauth (ID, username,
password, nas_ip, auth_result, reply_message, authdate)
VALUES (NULL, '%{User-Name}',
aes_encrypt('NA', 'abc123456def'), '%{NAS-IP-ADD
RESS}', '%{reply:Packet-Type}',
'%{control:My-Err-Message}',
'%S') -> INSERT INTO radpostauth (ID, username, passw
ord, nas_ip, auth_result, reply_message, authdate) VAL
UES (NULL, 'time2', aes_enc
rypt('NA', 'abc123456def'), '127.0.0.1',
'Access-Reject', '',
'2010-07-21 18:07:16')
[sql] expand: /var/log/radius/sqltrace.sql -> /var/log/radius/sqltrace.sql
rlm_sql (sql) in sql_postauth: query is INSERT INTO radpostauth
(ID, username, password, nas_ip, auth_result, reply_message, authdate)
VALUES (NULL, 'time2',
aes_encrypt('NA', 'abc123456def'),
'127.0.0.1', 'Access-Reject',
'', '2010-
07-21 18:07:16')
rlm_sql (sql): Reserving sql socket id: 2
rlm_sql_mysql: query: INSERT INTO radpostauth (ID, us
ername, password, nas_ip, auth_result, reply_message, authdate)
VALUES (NULL, 'time2',
aes_encrypt('NA', 'abc123456def'), '127.0.0.1',
'Access-Reject', '',
'2010-07-21 18:07:16')
rlm_sql (sql): Released sql socket id: 2
++[sql] returns ok
[reply_log] expand: /var/log/radius/radacct/%{Client-IP-Address}/reply-detai
l-%Y%m%d -> /var/log/radius/radacct/127.0.0.1/reply-detail-20100721
[reply_log] /var/log/radius/radacct/%{Client-IP-Address}/reply-detail-%Y%m%d exp
ands to /var/log/radius/radacct/127.0.0.1/reply-detail-20100721
[reply_log] expand: %t -> Wed Jul 21 18:07:16 2010
++[reply_log] returns ok
[attr_filter.access_reject] expand: %{User-Name} -> time2
attr_filter: Matched entry DEFAULT at line 11
++[attr_filter.access_reject] returns updated
Delaying reject of request 7 for 1 seconds
Going to the next request
Waking up in 0.9 seconds.
Sending delayed reject for request 7
Sending Access-Reject of id 7 to 127.0.0.1 port 48700
EAP-Message = 0x04070004
Message-Authenticator = 0x00000000000000000000000000000000
Waking up in 3.9 seconds.
Cleaning up request 0 ID 0 with timestamp +4
Cleaning up request 1 ID 1 with timestamp +4
Cleaning up request 2 ID 2 with timestamp +4
Cleaning up request 3 ID 3 with timestamp +4
Cleaning up request 4 ID 4 with timestamp +4
Cleaning up request 5 ID 5 with timestamp +4
Cleaning up request 6 ID 6 with timestamp +4
Waking up in 1.0 seconds.
Cleaning up request 7 ID 7 with timestamp +4
Ready to process requests.
----4. ends -------------------------
More information about the Freeradius-Users
mailing list