FreeRADIUS with some HP Multifunction printers
A.L.M.Buxey at lboro.ac.uk
A.L.M.Buxey at lboro.ac.uk
Wed Feb 11 10:38:31 CET 2009
hi,
<shuffle shuffle, mumble mumble>
heres the attachment that I forgot to attach....
alan
-------------- next part --------------
rad_recv: Access-Request packet from host 10.5.9.101 port 1812, id=121, length=157
NAS-IP-Address = 10.5.9.101
NAS-Port = 50016
Cisco-NAS-Port = "FastEthernet0/16"
NAS-Port-Type = Ethernet
User-Name = "test-printer"
Called-Station-Id = "00-0E-D7-74-D1-10"
Calling-Station-Id = "00-1F-29-23-BA-41"
Service-Type = Framed-User
Framed-MTU = 1500
EAP-Message = 0x0213000e0163637072696e746572
Message-Authenticator = 0x501fb031f42dff2b742572b61a8484b4
+- entering group authorize {...}
[preprocess] expand: %{Client-IP-Address} -> 10.5.9.101
[preprocess] expand: %{Client-IP-Address} -> 10.5.9.101
[preprocess] expand: %{Client-IP-Address} -> 10.5.9.101
++[preprocess] returns ok
[suffix] No '@' in User-Name = "test-printer", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[ntdomain] No '\' in User-Name = "test-printer", looking up realm NULL
[ntdomain] No such realm "NULL"
++[ntdomain] returns noop
++? if ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/)
expand: %{User-Name} -> test-printer
? Evaluating ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/) -> TRUE
++? if ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/) -> TRUE
++- entering if ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/) {...}
+++? if (!"%{2}" || ("%{2}" == "realm.org") || ("%{2}" == "realm.com") )
expand: %{2} ->
? Evaluating !("%{2}" ) -> FALSE
? Skipping ("%{2}" == "realm.org")
? Skipping ("%{2}" == "realm.com")
+++? if (!"%{2}" || ("%{2}" == "realm.org") || ("%{2}" == "realm.com") ) -> TRUE
+++- entering if (!"%{2}" || ("%{2}" == "realm.org") || ("%{2}" == "realm.com") ) {...}
++++[request] returns noop
+++- if (!"%{2}" || ("%{2}" == "realm.org") || ("%{2}" == "realm.com") ) returns noop
+++ ... skipping else for request 125: Preceding "if" was taken
++- if ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/) returns noop
++ ... skipping else for request 125: Preceding "if" was taken
++? if ("%{Called-Station-Id}" =~ /.*:testssid$/ || "%{NAS-IP-Address}" =~ /10.5\.2\.[2|3|5|6|7]$/ )
expand: %{Called-Station-Id} -> 00-0E-D7-74-D1-10
? Evaluating ("%{Called-Station-Id}" =~ /.*:testssid$/) -> FALSE
expand: %{NAS-IP-Address} -> 10.5.9.101
Evaluating ("%{NAS-IP-Address}" =~ /10.5\.2\.[2|3|5|6|7]$/) -> FALSE
++? if ("%{Called-Station-Id}" =~ /.*:testssid$/ || "%{NAS-IP-Address}" =~ /10.5\.2\.[2|3|5|6|7]$/ ) -> FALSE
expand: %{Realm} -> local
++- entering switch %{Realm} {...}
+++- entering case local {...}
++++- case local returns notfound
+++- switch %{Realm} returns notfound
++- switch %{Realm} returns notfound
add-dollar-sign: Could not find value pair for attribute Stripped-User-Name
++[add-dollar-sign] returns noop
strip-realm-name: Could not find value pair for attribute Stripped-User-Name
++[strip-realm-name] returns noop
remove-lboro: Could not find value pair for attribute Stripped-User-Name
++[remove-lboro] returns noop
[auth_log] expand: /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/radius/radacct/10.5.9.101/auth-detail-20090113
[auth_log] /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/radius/radacct/10.5.9.101/auth-detail-20090113
[auth_log] expand: %t -> Tue Jan 13 12:11:19 2009
++[auth_log] returns ok
++[mschap] returns noop
[eap] EAP packet type response id 19 length 14
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
[files] users: Matched entry DEFAULT at line 168
++[files] returns ok
[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] Initiate
[tls] Start returned 1
++[eap] returns handled
Sending Access-Challenge of id 121 to 10.5.9.101 port 1812
EAP-Message = 0x011400061920
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xe2037c98e21765e6e4abb08d09657962
Finished request 125.
Going to the next request
Waking up in 1.9 seconds.
rad_recv: Access-Request packet from host 10.5.9.101 port 1812, id=122, length=227
NAS-IP-Address = 10.5.9.101
NAS-Port = 50016
Cisco-NAS-Port = "FastEthernet0/16"
NAS-Port-Type = Ethernet
User-Name = "test-printer"
Called-Station-Id = "00-0E-D7-74-D1-10"
Calling-Station-Id = "00-1F-29-23-BA-41"
Service-Type = Framed-User
Framed-MTU = 1500
State = 0xe2037c98e21765e6e4abb08d09657962
EAP-Message = 0x0214004219800000003816030100330100002f030100000071f75af731ee6924885efc17fb4f6ffd30b37de93943aeaf0f5c8ec373000008000a0005000400090100
Message-Authenticator = 0xab22b1a4e5c7bf7fa972c1304df10498
+- entering group authorize {...}
[preprocess] expand: %{Client-IP-Address} -> 10.5.9.101
[preprocess] expand: %{Client-IP-Address} -> 10.5.9.101
[preprocess] expand: %{Client-IP-Address} -> 10.5.9.101
++[preprocess] returns ok
[suffix] No '@' in User-Name = "test-printer", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[ntdomain] No '\' in User-Name = "test-printer", looking up realm NULL
[ntdomain] No such realm "NULL"
++[ntdomain] returns noop
++? if ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/)
expand: %{User-Name} -> test-printer
? Evaluating ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/) -> TRUE
++? if ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/) -> TRUE
++- entering if ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/) {...}
+++? if (!"%{2}" || ("%{2}" == "realm.org") || ("%{2}" == "realm.com") )
expand: %{2} ->
? Evaluating !("%{2}" ) -> FALSE
? Skipping ("%{2}" == "realm.org")
? Skipping ("%{2}" == "realm.com")
+++? if (!"%{2}" || ("%{2}" == "realm.org") || ("%{2}" == "realm.com") ) -> TRUE
+++- entering if (!"%{2}" || ("%{2}" == "realm.org") || ("%{2}" == "realm.com") ) {...}
++++[request] returns noop
+++- if (!"%{2}" || ("%{2}" == "realm.org") || ("%{2}" == "realm.com") ) returns noop
+++ ... skipping else for request 126: Preceding "if" was taken
++- if ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/) returns noop
++ ... skipping else for request 126: Preceding "if" was taken
++? if ("%{Called-Station-Id}" =~ /.*:testssid$/ || "%{NAS-IP-Address}" =~ /10.5\.2\.[2|3|5|6|7]$/ )
expand: %{Called-Station-Id} -> 00-0E-D7-74-D1-10
? Evaluating ("%{Called-Station-Id}" =~ /.*:testssid$/) -> FALSE
expand: %{NAS-IP-Address} -> 10.5.9.101
Evaluating ("%{NAS-IP-Address}" =~ /10.5\.2\.[2|3|5|6|7]$/) -> FALSE
++? if ("%{Called-Station-Id}" =~ /.*:testssid$/ || "%{NAS-IP-Address}" =~ /10.5\.2\.[2|3|5|6|7]$/ ) -> FALSE
expand: %{Realm} -> local
++- entering switch %{Realm} {...}
+++- entering case local {...}
++++- case local returns notfound
+++- switch %{Realm} returns notfound
++- switch %{Realm} returns notfound
add-dollar-sign: Could not find value pair for attribute Stripped-User-Name
++[add-dollar-sign] returns noop
strip-realm-name: Could not find value pair for attribute Stripped-User-Name
++[strip-realm-name] returns noop
remove-lboro: Could not find value pair for attribute Stripped-User-Name
++[remove-lboro] returns noop
[auth_log] expand: /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/radius/radacct/10.5.9.101/auth-detail-20090113
[auth_log] /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/radius/radacct/10.5.9.101/auth-detail-20090113
[auth_log] expand: %t -> Tue Jan 13 12:11:19 2009
++[auth_log] returns ok
++[mschap] returns noop
[eap] EAP packet type response id 20 length 66
[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 56
[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 0033], ClientHello
[peap] TLS_accept: SSLv3 read client hello A
[peap] >>> TLS 1.0 Handshake [length 002a], ServerHello
[peap] TLS_accept: SSLv3 write server hello A
[peap] >>> TLS 1.0 Handshake [length 0778], Certificate
[peap] TLS_accept: SSLv3 write certificate A
[peap] >>> TLS 1.0 Handshake [length 0004], ServerHelloDone
[peap] TLS_accept: SSLv3 write server done A
[peap] TLS_accept: SSLv3 flush data
[peap] TLS_accept: Need to read more data: SSLv3 read client certificate A
In SSL Handshake Phase
In SSL Accept mode
[peap] eaptls_process returned 13
[peap] EAPTLS_HANDLED
++[eap] returns handled
Sending Access-Challenge of id 122 to 10.5.9.101 port 1812
EAP-Message = 0x0115040019c0000007b5160301002a020000260301496c84e73294cf0206b92c509f35d8825cc936b4b1d00e01347f0798c8d38c4300000a0016030107780b00077400077100042c3082042830820391a00302010202015e300d06092a864886f70d01010405003081e5310b3009060355040613024742311730150603550408130e4c65696365737465727368697265311530130603550407130c4c6f756768626f726f7567683120301e060355040a13174c6f756768626f726f75676820556e6976657273697479311b3019060355040b1312436f6d707574696e67205365727669636573313630340603550403132d4c6f756768626f726f756768
EAP-Message = 0x20556e697665727369747920436572746966696361746520417574686f72697479312f302d06092a864886f70d01090116204365727469666963617465417574686f72697479406c626f726f2e61632e756b301e170d3036303730333136313034375a170d3132303833313136313034375a3081c8310b3009060355040613024742311730150603550408130e4c65696365737465727368697265311530130603550407130c4c6f756768626f726f7567683120301e060355040a13174c6f756768626f726f75676820556e6976657273697479311b3019060355040b1312436f6d707574696e67205365727669636573311b30190603550403131272
EAP-Message = 0x61646975732e6c626f726f2e61632e756b312d302b06092a864886f70d010901161e636f6d707574696e672e7365727669636573406c626f726f2e61632e756b30820122300d06092a864886f70d01010105000382010f003082010a0282010100c4ba691d26b4bc2ae2bd7d9e8be96868ed2c919944e3a837eaeacd4ca3d8ce8d2686ab1f62470ae672a070e51a96a95d01d6a0a583dd4cf5d98f171e85887afe91981f95fff84d87fd40b32fbb2b29b47acd8a0223f691809e55321e3899978049b5e71ab5956f6b52838d1f408a56b80bf67edc70f234928a728f70707b62b7872a607da926dfbf111c991ce576fac4a07e3cae01f27f3dc539ec93
EAP-Message = 0xd5f2f86867e54aa8e44db1630893e0f02ff29b57cc700fc90a469ff5da5c40296f5cfcd193a30054ff50c07bbd226e31a379df2406de43ae5fa0406a646e240d0682da21d4f1d3d0f578258f5422b37a699549c07787d56020367da70870985e8113f08f0203010001a37f307d303006096086480186f842010404231621687474703a2f2f63726c2e6c626f726f2e61632e756b2f63612d63726c2e70656d302106096086480186f842010d04141612436f6d707574696e67205365727669636573301106096086480186f842010104040302064030130603551d25040c300a06082b06010505070301300d06092a864886f70d010104050003818100
EAP-Message = 0xa46e005a7d7653dd96c94d97
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xe2037c98e31665e6e4abb08d09657962
Finished request 126.
Going to the next request
Waking up in 1.9 seconds.
rad_recv: Access-Request packet from host 10.5.9.101 port 1812, id=123, length=167
NAS-IP-Address = 10.5.9.101
NAS-Port = 50016
Cisco-NAS-Port = "FastEthernet0/16"
NAS-Port-Type = Ethernet
User-Name = "test-printer"
Called-Station-Id = "00-0E-D7-74-D1-10"
Calling-Station-Id = "00-1F-29-23-BA-41"
Service-Type = Framed-User
Framed-MTU = 1500
State = 0xe2037c98e31665e6e4abb08d09657962
EAP-Message = 0x021500061900
Message-Authenticator = 0x65f927e38679b0049aa3ac7b9e1115f7
+- entering group authorize {...}
[preprocess] expand: %{Client-IP-Address} -> 10.5.9.101
[preprocess] expand: %{Client-IP-Address} -> 10.5.9.101
[preprocess] expand: %{Client-IP-Address} -> 10.5.9.101
++[preprocess] returns ok
[suffix] No '@' in User-Name = "test-printer", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[ntdomain] No '\' in User-Name = "test-printer", looking up realm NULL
[ntdomain] No such realm "NULL"
++[ntdomain] returns noop
++? if ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/)
expand: %{User-Name} -> test-printer
? Evaluating ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/) -> TRUE
++? if ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/) -> TRUE
++- entering if ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/) {...}
+++? if (!"%{2}" || ("%{2}" == "realm.org") || ("%{2}" == "realm.com") )
expand: %{2} ->
? Evaluating !("%{2}" ) -> FALSE
? Skipping ("%{2}" == "realm.org")
? Skipping ("%{2}" == "realm.com")
+++? if (!"%{2}" || ("%{2}" == "realm.org") || ("%{2}" == "realm.com") ) -> TRUE
+++- entering if (!"%{2}" || ("%{2}" == "realm.org") || ("%{2}" == "realm.com") ) {...}
++++[request] returns noop
+++- if (!"%{2}" || ("%{2}" == "realm.org") || ("%{2}" == "realm.com") ) returns noop
+++ ... skipping else for request 127: Preceding "if" was taken
++- if ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/) returns noop
++ ... skipping else for request 127: Preceding "if" was taken
++? if ("%{Called-Station-Id}" =~ /.*:testssid$/ || "%{NAS-IP-Address}" =~ /10.5\.2\.[2|3|5|6|7]$/ )
expand: %{Called-Station-Id} -> 00-0E-D7-74-D1-10
? Evaluating ("%{Called-Station-Id}" =~ /.*:testssid$/) -> FALSE
expand: %{NAS-IP-Address} -> 10.5.9.101
Evaluating ("%{NAS-IP-Address}" =~ /10.5\.2\.[2|3|5|6|7]$/) -> FALSE
++? if ("%{Called-Station-Id}" =~ /.*:testssid$/ || "%{NAS-IP-Address}" =~ /10.5\.2\.[2|3|5|6|7]$/ ) -> FALSE
expand: %{Realm} -> local
++- entering switch %{Realm} {...}
+++- entering case local {...}
++++- case local returns notfound
+++- switch %{Realm} returns notfound
++- switch %{Realm} returns notfound
add-dollar-sign: Could not find value pair for attribute Stripped-User-Name
++[add-dollar-sign] returns noop
strip-realm-name: Could not find value pair for attribute Stripped-User-Name
++[strip-realm-name] returns noop
remove-lboro: Could not find value pair for attribute Stripped-User-Name
++[remove-lboro] returns noop
[auth_log] expand: /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/radius/radacct/10.5.9.101/auth-detail-20090113
[auth_log] /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/radius/radacct/10.5.9.101/auth-detail-20090113
[auth_log] expand: %t -> Tue Jan 13 12:11:19 2009
++[auth_log] returns ok
++[mschap] returns noop
[eap] EAP packet type response id 21 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 123 to 10.5.9.101 port 1812
EAP-Message = 0x011603c51900fd8b8b1442f059168ce5789c4df66d54eb775cfe263f988c2615bfb4aa699a1044ef4753f477b224dc5c42f607685092d9f2aff5c369c03137b031b3a08ac35074301f967418bfb77a7cd41c64452aeccab02053fe837216f541a9c848c284190eb8c589144ef2d1c1463a57a27b0d4fda0d001900033f3082033b308202a4020100300d06092a864886f70d01010405003081e5310b3009060355040613024742311730150603550408130e4c65696365737465727368697265311530130603550407130c4c6f756768626f726f7567683120301e060355040a13174c6f756768626f726f75676820556e6976657273697479311b3019
EAP-Message = 0x060355040b1312436f6d707574696e67205365727669636573313630340603550403132d4c6f756768626f726f75676820556e697665727369747920436572746966696361746520417574686f72697479312f302d06092a864886f70d01090116204365727469666963617465417574686f72697479406c626f726f2e61632e756b301e170d3938303831393134333435345a170d3139313233313134333435345a3081e5310b3009060355040613024742311730150603550408130e4c65696365737465727368697265311530130603550407130c4c6f756768626f726f7567683120301e060355040a13174c6f756768626f726f75676820556e69
EAP-Message = 0x76657273697479311b3019060355040b1312436f6d707574696e67205365727669636573313630340603550403132d4c6f756768626f726f75676820556e697665727369747920436572746966696361746520417574686f72697479312f302d06092a864886f70d01090116204365727469666963617465417574686f72697479406c626f726f2e61632e756b30819f300d06092a864886f70d010101050003818d0030818902818100a79af8b26aef34952ce192442557a63755f115d1d45396a93d59bdff479f126fa56fb397e522f0b80fc66825688ae0c40823dc3d9d6c6f4caf5c0b346e05a20e044be0afe2f589ee0c581cd772c9dbc34795d4
EAP-Message = 0x0a15a6df4c9c6ca84c7a3021b027a2770db3baf1574331d4d1934ef97fb5d701fca31f57a8a4a90df5d56bc55d0203010001300d06092a864886f70d010104050003818100204f5bccc5dec874e0a74098aa417367f3607c68e303ee25c4e9c7b024109031aff457a38fa5a0a87b0ce09634da45aad16f11db7a3947d4e2c189f38257ca628acbf3973cd2b99343c78c8fdb9d2fa6ff4999c516eb98d9e5a0cba7dd6573cdddf2e7b40342996a650699e2983b8c777340f268bea8dff044171793947a3f7d16030100040e000000
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xe2037c98e01565e6e4abb08d09657962
Finished request 127.
Going to the next request
Waking up in 1.8 seconds.
rad_recv: Access-Request packet from host 10.5.9.101 port 1812, id=124, length=491
NAS-IP-Address = 10.5.9.101
NAS-Port = 50016
Cisco-NAS-Port = "FastEthernet0/16"
NAS-Port-Type = Ethernet
User-Name = "test-printer"
Called-Station-Id = "00-0E-D7-74-D1-10"
Calling-Station-Id = "00-1F-29-23-BA-41"
Service-Type = Framed-User
Framed-MTU = 1500
State = 0xe2037c98e01565e6e4abb08d09657962
EAP-Message = 0x0216014819800000013e160301010610000102010059920db7d3869f7f2d19a21fbd598e445396b07e094798353ba1cfe07b922fc5d7e5b42a7a32f52fe88fbe077fe2525f0545ff66ce847b133c72db68818476260c97f138248b3ba706a59dfdfa6cd53c68adc6d4367e878f29856fc77085b73c5d75a6d24c38931918d093505f146fabc7a8f1e31a2dbb6f5296816d73a28b252aba4009c7c0e811893dd2f638437ec65b040ba3b3ded9b2c55d260e5ac8065ef6b6a49c8196218646d1835160bf3f9e4b1cf976805d03e343b30729863740a66fd51df32349e39008543e6e0843497bc19bea00b16e3fcf68fe790500f663691688186c50c3dfda
EAP-Message = 0xddca770f9c19ec7325ca13dd085022b6c4af3903e8db6c291403010001011603010028837d5eada8c3f5a3fff47ca8e93018908779448410dc8d6414dc8263e3c00df3d2c430a83c8b33d1
Message-Authenticator = 0x3e8b8380345907fb60eb555854a805cb
+- entering group authorize {...}
[preprocess] expand: %{Client-IP-Address} -> 10.5.9.101
[preprocess] expand: %{Client-IP-Address} -> 10.5.9.101
[preprocess] expand: %{Client-IP-Address} -> 10.5.9.101
++[preprocess] returns ok
[suffix] No '@' in User-Name = "test-printer", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[ntdomain] No '\' in User-Name = "test-printer", looking up realm NULL
[ntdomain] No such realm "NULL"
++[ntdomain] returns noop
++? if ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/)
expand: %{User-Name} -> test-printer
? Evaluating ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/) -> TRUE
++? if ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/) -> TRUE
++- entering if ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/) {...}
+++? if (!"%{2}" || ("%{2}" == "realm.org") || ("%{2}" == "realm.com") )
expand: %{2} ->
? Evaluating !("%{2}" ) -> FALSE
? Skipping ("%{2}" == "realm.org")
? Skipping ("%{2}" == "realm.com")
+++? if (!"%{2}" || ("%{2}" == "realm.org") || ("%{2}" == "realm.com") ) -> TRUE
+++- entering if (!"%{2}" || ("%{2}" == "realm.org") || ("%{2}" == "realm.com") ) {...}
++++[request] returns noop
+++- if (!"%{2}" || ("%{2}" == "realm.org") || ("%{2}" == "realm.com") ) returns noop
+++ ... skipping else for request 128: Preceding "if" was taken
++- if ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/) returns noop
++ ... skipping else for request 128: Preceding "if" was taken
++? if ("%{Called-Station-Id}" =~ /.*:testssid$/ || "%{NAS-IP-Address}" =~ /10.5\.2\.[2|3|5|6|7]$/ )
expand: %{Called-Station-Id} -> 00-0E-D7-74-D1-10
? Evaluating ("%{Called-Station-Id}" =~ /.*:testssid$/) -> FALSE
expand: %{NAS-IP-Address} -> 10.5.9.101
Evaluating ("%{NAS-IP-Address}" =~ /10.5\.2\.[2|3|5|6|7]$/) -> FALSE
++? if ("%{Called-Station-Id}" =~ /.*:testssid$/ || "%{NAS-IP-Address}" =~ /10.5\.2\.[2|3|5|6|7]$/ ) -> FALSE
expand: %{Realm} -> local
++- entering switch %{Realm} {...}
+++- entering case local {...}
++++- case local returns notfound
+++- switch %{Realm} returns notfound
++- switch %{Realm} returns notfound
add-dollar-sign: Could not find value pair for attribute Stripped-User-Name
++[add-dollar-sign] returns noop
strip-realm-name: Could not find value pair for attribute Stripped-User-Name
++[strip-realm-name] returns noop
remove-lboro: Could not find value pair for attribute Stripped-User-Name
++[remove-lboro] returns noop
[auth_log] expand: /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/radius/radacct/10.5.9.101/auth-detail-20090113
[auth_log] /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/radius/radacct/10.5.9.101/auth-detail-20090113
[auth_log] expand: %t -> Tue Jan 13 12:11:19 2009
++[auth_log] returns ok
++[mschap] returns noop
[eap] EAP packet type response id 22 length 253
[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 318
[peap] Length Included
[peap] eaptls_verify returned 11
[peap] <<< TLS 1.0 Handshake [length 0106], ClientKeyExchange
[peap] TLS_accept: SSLv3 read client key exchange A
[peap] <<< TLS 1.0 ChangeCipherSpec [length 0001]
[peap] <<< TLS 1.0 Handshake [length 0010], Finished
[peap] TLS_accept: SSLv3 read finished A
[peap] >>> TLS 1.0 ChangeCipherSpec [length 0001]
[peap] TLS_accept: SSLv3 write change cipher spec A
[peap] >>> TLS 1.0 Handshake [length 0010], Finished
[peap] TLS_accept: SSLv3 write finished A
[peap] TLS_accept: SSLv3 flush data
[peap] (other): SSL negotiation finished successfully
SSL Connection Established
[peap] eaptls_process returned 13
[peap] EAPTLS_HANDLED
++[eap] returns handled
Sending Access-Challenge of id 124 to 10.5.9.101 port 1812
EAP-Message = 0x01170039190014030100010116030100281477d3dcc972b3184c5a2156704f69c31c3aadatestssid14b12866eb7e0d3804faf07a261d0ee1598371
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xe2037c98e11465e6e4abb08d09657962
Finished request 128.
Going to the next request
Waking up in 1.7 seconds.
rad_recv: Access-Request packet from host 10.5.9.101 port 1812, id=125, length=167
NAS-IP-Address = 10.5.9.101
NAS-Port = 50016
Cisco-NAS-Port = "FastEthernet0/16"
NAS-Port-Type = Ethernet
User-Name = "test-printer"
Called-Station-Id = "00-0E-D7-74-D1-10"
Calling-Station-Id = "00-1F-29-23-BA-41"
Service-Type = Framed-User
Framed-MTU = 1500
State = 0xe2037c98e11465e6e4abb08d09657962
EAP-Message = 0x021700061900
Message-Authenticator = 0x22f732158d3ab8d9f00309fd764cb38b
+- entering group authorize {...}
[preprocess] expand: %{Client-IP-Address} -> 10.5.9.101
[preprocess] expand: %{Client-IP-Address} -> 10.5.9.101
[preprocess] expand: %{Client-IP-Address} -> 10.5.9.101
++[preprocess] returns ok
[suffix] No '@' in User-Name = "test-printer", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[ntdomain] No '\' in User-Name = "test-printer", looking up realm NULL
[ntdomain] No such realm "NULL"
++[ntdomain] returns noop
++? if ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/)
expand: %{User-Name} -> test-printer
? Evaluating ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/) -> TRUE
++? if ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/) -> TRUE
++- entering if ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/) {...}
+++? if (!"%{2}" || ("%{2}" == "realm.org") || ("%{2}" == "realm.com") )
expand: %{2} ->
? Evaluating !("%{2}" ) -> FALSE
? Skipping ("%{2}" == "realm.org")
? Skipping ("%{2}" == "realm.com")
+++? if (!"%{2}" || ("%{2}" == "realm.org") || ("%{2}" == "realm.com") ) -> TRUE
+++- entering if (!"%{2}" || ("%{2}" == "realm.org") || ("%{2}" == "realm.com") ) {...}
++++[request] returns noop
+++- if (!"%{2}" || ("%{2}" == "realm.org") || ("%{2}" == "realm.com") ) returns noop
+++ ... skipping else for request 129: Preceding "if" was taken
++- if ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/) returns noop
++ ... skipping else for request 129: Preceding "if" was taken
++? if ("%{Called-Station-Id}" =~ /.*:testssid$/ || "%{NAS-IP-Address}" =~ /10.5\.2\.[2|3|5|6|7]$/ )
expand: %{Called-Station-Id} -> 00-0E-D7-74-D1-10
? Evaluating ("%{Called-Station-Id}" =~ /.*:testssid$/) -> FALSE
expand: %{NAS-IP-Address} -> 10.5.9.101
Evaluating ("%{NAS-IP-Address}" =~ /10.5\.2\.[2|3|5|6|7]$/) -> FALSE
++? if ("%{Called-Station-Id}" =~ /.*:testssid$/ || "%{NAS-IP-Address}" =~ /10.5\.2\.[2|3|5|6|7]$/ ) -> FALSE
expand: %{Realm} -> local
++- entering switch %{Realm} {...}
+++- entering case local {...}
++++- case local returns notfound
+++- switch %{Realm} returns notfound
++- switch %{Realm} returns notfound
add-dollar-sign: Could not find value pair for attribute Stripped-User-Name
++[add-dollar-sign] returns noop
strip-realm-name: Could not find value pair for attribute Stripped-User-Name
++[strip-realm-name] returns noop
remove-lboro: Could not find value pair for attribute Stripped-User-Name
++[remove-lboro] returns noop
[auth_log] expand: /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/radius/radacct/10.5.9.101/auth-detail-20090113
[auth_log] /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/radius/radacct/10.5.9.101/auth-detail-20090113
[auth_log] expand: %t -> Tue Jan 13 12:11:20 2009
++[auth_log] returns ok
++[mschap] returns noop
[eap] EAP packet type response id 23 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 125 to 10.5.9.101 port 1812
EAP-Message = 0x0118002b1900170301002035c0fbf32d35642acdec70da3240b384f99158c6b74166c6e43c4890a5c3d46f
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xe2037c98e61b65e6e4abb08d09657962
Finished request 129.
Going to the next request
Waking up in 1.6 seconds.
rad_recv: Access-Request packet from host 10.5.9.101 port 1812, id=126, length=241
NAS-IP-Address = 10.5.9.101
NAS-Port = 50016
Cisco-NAS-Port = "FastEthernet0/16"
NAS-Port-Type = Ethernet
User-Name = "test-printer"
Called-Station-Id = "00-0E-D7-74-D1-10"
Calling-Station-Id = "00-1F-29-23-BA-41"
Service-Type = Framed-User
Framed-MTU = 1500
State = 0xe2037c98e61b65e6e4abb08d09657962
EAP-Message = 0x0218005019001703010018e8441c5ec8db89f4e99f497e16c342825132a6b06c7c846617030100287ac5a6120a0e036e4f014ee4750a08b42b4cb9e745672f8799dab41d341b226dcaf4cdc613e7f293
Message-Authenticator = 0x88db88e6636aa5caa8143ad68b5594e5
+- entering group authorize {...}
[preprocess] expand: %{Client-IP-Address} -> 10.5.9.101
[preprocess] expand: %{Client-IP-Address} -> 10.5.9.101
[preprocess] expand: %{Client-IP-Address} -> 10.5.9.101
++[preprocess] returns ok
[suffix] No '@' in User-Name = "test-printer", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[ntdomain] No '\' in User-Name = "test-printer", looking up realm NULL
[ntdomain] No such realm "NULL"
++[ntdomain] returns noop
++? if ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/)
expand: %{User-Name} -> test-printer
? Evaluating ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/) -> TRUE
++? if ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/) -> TRUE
++- entering if ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/) {...}
+++? if (!"%{2}" || ("%{2}" == "realm.org") || ("%{2}" == "realm.com") )
expand: %{2} ->
? Evaluating !("%{2}" ) -> FALSE
? Skipping ("%{2}" == "realm.org")
? Skipping ("%{2}" == "realm.com")
+++? if (!"%{2}" || ("%{2}" == "realm.org") || ("%{2}" == "realm.com") ) -> TRUE
+++- entering if (!"%{2}" || ("%{2}" == "realm.org") || ("%{2}" == "realm.com") ) {...}
++++[request] returns noop
+++- if (!"%{2}" || ("%{2}" == "realm.org") || ("%{2}" == "realm.com") ) returns noop
+++ ... skipping else for request 130: Preceding "if" was taken
++- if ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/) returns noop
++ ... skipping else for request 130: Preceding "if" was taken
++? if ("%{Called-Station-Id}" =~ /.*:testssid$/ || "%{NAS-IP-Address}" =~ /10.5\.2\.[2|3|5|6|7]$/ )
expand: %{Called-Station-Id} -> 00-0E-D7-74-D1-10
? Evaluating ("%{Called-Station-Id}" =~ /.*:testssid$/) -> FALSE
expand: %{NAS-IP-Address} -> 10.5.9.101
Evaluating ("%{NAS-IP-Address}" =~ /10.5\.2\.[2|3|5|6|7]$/) -> FALSE
++? if ("%{Called-Station-Id}" =~ /.*:testssid$/ || "%{NAS-IP-Address}" =~ /10.5\.2\.[2|3|5|6|7]$/ ) -> FALSE
expand: %{Realm} -> local
++- entering switch %{Realm} {...}
+++- entering case local {...}
++++- case local returns notfound
+++- switch %{Realm} returns notfound
++- switch %{Realm} returns notfound
add-dollar-sign: Could not find value pair for attribute Stripped-User-Name
++[add-dollar-sign] returns noop
strip-realm-name: Could not find value pair for attribute Stripped-User-Name
++[strip-realm-name] returns noop
remove-lboro: Could not find value pair for attribute Stripped-User-Name
++[remove-lboro] returns noop
[auth_log] expand: /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/radius/radacct/10.5.9.101/auth-detail-20090113
[auth_log] /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/radius/radacct/10.5.9.101/auth-detail-20090113
[auth_log] expand: %t -> Tue Jan 13 12:11:20 2009
++[auth_log] returns ok
++[mschap] returns noop
[eap] EAP packet type response id 24 length 80
[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] Got something weird.
[peap] Tunneled data is invalid.
[eap] Handler failed in EAP/peap
[eap] Failed in EAP select
++[eap] returns invalid
Failed to authenticate the user.
Login incorrect: [test-printer] (from client Cisco-AP port 50016 cli 00-1F-29-23-BA-41)
Using Post-Auth-Type Reject
+- entering group REJECT {...}
[attr_filter.access_reject] expand: %{User-Name} -> test-printer
attr_filter: Matched entry DEFAULT at line 11
++[attr_filter.access_reject] returns updated
Delaying reject of request 130 for 1 seconds
Going to the next request
Waking up in 0.9 seconds.
Sending delayed reject for request 130
Sending Access-Reject of id 126 to 10.5.9.101 port 1812
EAP-Message = 0x04180004
Message-Authenticator = 0x00000000000000000000000000000000
Waking up in 0.6 seconds.
rad_recv: Access-Request packet from host 10.5.9.101 port 1812, id=127, length=157
NAS-IP-Address = 10.5.9.101
NAS-Port = 50016
Cisco-NAS-Port = "FastEthernet0/16"
NAS-Port-Type = Ethernet
User-Name = "test-printer"
Called-Station-Id = "00-0E-D7-74-D1-10"
Calling-Station-Id = "00-1F-29-23-BA-41"
Service-Type = Framed-User
Framed-MTU = 1500
EAP-Message = 0x0219000e0163637072696e746572
Message-Authenticator = 0x3c6d2a722f98ffbtestssid9beabd8a2657fe
+- entering group authorize {...}
[preprocess] expand: %{Client-IP-Address} -> 10.5.9.101
[preprocess] expand: %{Client-IP-Address} -> 10.5.9.101
[preprocess] expand: %{Client-IP-Address} -> 10.5.9.101
++[preprocess] returns ok
[suffix] No '@' in User-Name = "test-printer", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[ntdomain] No '\' in User-Name = "test-printer", looking up realm NULL
[ntdomain] No such realm "NULL"
++[ntdomain] returns noop
++? if ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/)
expand: %{User-Name} -> test-printer
? Evaluating ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/) -> TRUE
++? if ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/) -> TRUE
++- entering if ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/) {...}
+++? if (!"%{2}" || ("%{2}" == "realm.org") || ("%{2}" == "realm.com") )
expand: %{2} ->
? Evaluating !("%{2}" ) -> FALSE
? Skipping ("%{2}" == "realm.org")
? Skipping ("%{2}" == "realm.com")
+++? if (!"%{2}" || ("%{2}" == "realm.org") || ("%{2}" == "realm.com") ) -> TRUE
+++- entering if (!"%{2}" || ("%{2}" == "realm.org") || ("%{2}" == "realm.com") ) {...}
++++[request] returns noop
+++- if (!"%{2}" || ("%{2}" == "realm.org") || ("%{2}" == "realm.com") ) returns noop
+++ ... skipping else for request 131: Preceding "if" was taken
++- if ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/) returns noop
++ ... skipping else for request 131: Preceding "if" was taken
++? if ("%{Called-Station-Id}" =~ /.*:testssid$/ || "%{NAS-IP-Address}" =~ /10.5\.2\.[2|3|5|6|7]$/ )
expand: %{Called-Station-Id} -> 00-0E-D7-74-D1-10
? Evaluating ("%{Called-Station-Id}" =~ /.*:testssid$/) -> FALSE
expand: %{NAS-IP-Address} -> 10.5.9.101
Evaluating ("%{NAS-IP-Address}" =~ /10.5\.2\.[2|3|5|6|7]$/) -> FALSE
++? if ("%{Called-Station-Id}" =~ /.*:testssid$/ || "%{NAS-IP-Address}" =~ /10.5\.2\.[2|3|5|6|7]$/ ) -> FALSE
expand: %{Realm} -> local
++- entering switch %{Realm} {...}
+++- entering case local {...}
++++- case local returns notfound
+++- switch %{Realm} returns notfound
++- switch %{Realm} returns notfound
add-dollar-sign: Could not find value pair for attribute Stripped-User-Name
++[add-dollar-sign] returns noop
strip-realm-name: Could not find value pair for attribute Stripped-User-Name
++[strip-realm-name] returns noop
remove-lboro: Could not find value pair for attribute Stripped-User-Name
++[remove-lboro] returns noop
[auth_log] expand: /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/radius/radacct/10.5.9.101/auth-detail-20090113
[auth_log] /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/radius/radacct/10.5.9.101/auth-detail-20090113
[auth_log] expand: %t -> Tue Jan 13 12:11:21 2009
++[auth_log] returns ok
++[mschap] returns noop
[eap] EAP packet type response id 25 length 14
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
[files] users: Matched entry DEFAULT at line 168
++[files] returns ok
[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] Initiate
[tls] Start returned 1
++[eap] returns handled
Sending Access-Challenge of id 127 to 10.5.9.101 port 1812
EAP-Message = 0x011a00061920
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xf8bf8318f8a59a932e088bdf9b3f173d
Finished request 131.
Going to the next request
Waking up in 0.6 seconds.
rad_recv: Access-Request packet from host 10.5.9.101 port 1812, id=128, length=227
NAS-IP-Address = 10.5.9.101
NAS-Port = 50016
Cisco-NAS-Port = "FastEthernet0/16"
NAS-Port-Type = Ethernet
User-Name = "test-printer"
Called-Station-Id = "00-0E-D7-74-D1-10"
Calling-Station-Id = "00-1F-29-23-BA-41"
Service-Type = Framed-User
Framed-MTU = 1500
State = 0xf8bf8318f8a59a932e088bdf9b3f173d
EAP-Message = 0x021a004219800000003816030100330100002f03010000007359d73f6b50ccefbea655d2ae2c33650f510a4d1224336b61f5d355d1000008000a0005000400090100
Message-Authenticator = 0x21d35eda6b26f82d2990513379d0aa9d
+- entering group authorize {...}
[preprocess] expand: %{Client-IP-Address} -> 10.5.9.101
[preprocess] expand: %{Client-IP-Address} -> 10.5.9.101
[preprocess] expand: %{Client-IP-Address} -> 10.5.9.101
++[preprocess] returns ok
[suffix] No '@' in User-Name = "test-printer", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[ntdomain] No '\' in User-Name = "test-printer", looking up realm NULL
[ntdomain] No such realm "NULL"
++[ntdomain] returns noop
++? if ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/)
expand: %{User-Name} -> test-printer
? Evaluating ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/) -> TRUE
++? if ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/) -> TRUE
++- entering if ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/) {...}
+++? if (!"%{2}" || ("%{2}" == "realm.org") || ("%{2}" == "realm.com") )
expand: %{2} ->
? Evaluating !("%{2}" ) -> FALSE
? Skipping ("%{2}" == "realm.org")
? Skipping ("%{2}" == "realm.com")
+++? if (!"%{2}" || ("%{2}" == "realm.org") || ("%{2}" == "realm.com") ) -> TRUE
+++- entering if (!"%{2}" || ("%{2}" == "realm.org") || ("%{2}" == "realm.com") ) {...}
++++[request] returns noop
+++- if (!"%{2}" || ("%{2}" == "realm.org") || ("%{2}" == "realm.com") ) returns noop
+++ ... skipping else for request 132: Preceding "if" was taken
++- if ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/) returns noop
++ ... skipping else for request 132: Preceding "if" was taken
++? if ("%{Called-Station-Id}" =~ /.*:testssid$/ || "%{NAS-IP-Address}" =~ /10.5\.2\.[2|3|5|6|7]$/ )
expand: %{Called-Station-Id} -> 00-0E-D7-74-D1-10
? Evaluating ("%{Called-Station-Id}" =~ /.*:testssid$/) -> FALSE
expand: %{NAS-IP-Address} -> 10.5.9.101
Evaluating ("%{NAS-IP-Address}" =~ /10.5\.2\.[2|3|5|6|7]$/) -> FALSE
++? if ("%{Called-Station-Id}" =~ /.*:testssid$/ || "%{NAS-IP-Address}" =~ /10.5\.2\.[2|3|5|6|7]$/ ) -> FALSE
expand: %{Realm} -> local
++- entering switch %{Realm} {...}
+++- entering case local {...}
++++- case local returns notfound
+++- switch %{Realm} returns notfound
++- switch %{Realm} returns notfound
add-dollar-sign: Could not find value pair for attribute Stripped-User-Name
++[add-dollar-sign] returns noop
strip-realm-name: Could not find value pair for attribute Stripped-User-Name
++[strip-realm-name] returns noop
remove-lboro: Could not find value pair for attribute Stripped-User-Name
++[remove-lboro] returns noop
[auth_log] expand: /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/radius/radacct/10.5.9.101/auth-detail-20090113
[auth_log] /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/radius/radacct/10.5.9.101/auth-detail-20090113
[auth_log] expand: %t -> Tue Jan 13 12:11:21 2009
++[auth_log] returns ok
++[mschap] returns noop
[eap] EAP packet type response id 26 length 66
[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 56
[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 0033], ClientHello
[peap] TLS_accept: SSLv3 read client hello A
[peap] >>> TLS 1.0 Handshake [length 002a], ServerHello
[peap] TLS_accept: SSLv3 write server hello A
[peap] >>> TLS 1.0 Handshake [length 0778], Certificate
[peap] TLS_accept: SSLv3 write certificate A
[peap] >>> TLS 1.0 Handshake [length 0004], ServerHelloDone
[peap] TLS_accept: SSLv3 write server done A
[peap] TLS_accept: SSLv3 flush data
[peap] TLS_accept: Need to read more data: SSLv3 read client certificate A
In SSL Handshake Phase
In SSL Accept mode
[peap] eaptls_process returned 13
[peap] EAPTLS_HANDLED
++[eap] returns handled
Sending Access-Challenge of id 128 to 10.5.9.101 port 1812
EAP-Message = 0x011b040019c0000007b5160301002a020000260301496c84e97b1841e77db7dbd1957b8c08b1f896f8b4db87bc26caa4b196d3e84d00000a0016030107780b00077400077100042c3082042830820391a00302010202015e300d06092a864886f70d01010405003081e5310b3009060355040613024742311730150603550408130e4c65696365737465727368697265311530130603550407130c4c6f756768626f726f7567683120301e060355040a13174c6f756768626f726f75676820556e6976657273697479311b3019060355040b1312436f6d707574696e67205365727669636573313630340603550403132d4c6f756768626f726f756768
EAP-Message = 0x20556e697665727369747920436572746966696361746520417574686f72697479312f302d06092a864886f70d01090116204365727469666963617465417574686f72697479406c626f726f2e61632e756b301e170d3036303730333136313034375a170d3132303833313136313034375a3081c8310b3009060355040613024742311730150603550408130e4c65696365737465727368697265311530130603550407130c4c6f756768626f726f7567683120301e060355040a13174c6f756768626f726f75676820556e6976657273697479311b3019060355040b1312436f6d707574696e67205365727669636573311b30190603550403131272
EAP-Message = 0x61646975732e6c626f726f2e61632e756b312d302b06092a864886f70d010901161e636f6d707574696e672e7365727669636573406c626f726f2e61632e756b30820122300d06092a864886f70d01010105000382010f003082010a0282010100c4ba691d26b4bc2ae2bd7d9e8be96868ed2c919944e3a837eaeacd4ca3d8ce8d2686ab1f62470ae672a070e51a96a95d01d6a0a583dd4cf5d98f171e85887afe91981f95fff84d87fd40b32fbb2b29b47acd8a0223f691809e55321e3899978049b5e71ab5956f6b52838d1f408a56b80bf67edc70f234928a728f70707b62b7872a607da926dfbf111c991ce576fac4a07e3cae01f27f3dc539ec93
EAP-Message = 0xd5f2f86867e54aa8e44db1630893e0f02ff29b57cc700fc90a469ff5da5c40296f5cfcd193a30054ff50c07bbd226e31a379df2406de43ae5fa0406a646e240d0682da21d4f1d3d0f578258f5422b37a699549c07787d56020367da70870985e8113f08f0203010001a37f307d303006096086480186f842010404231621687474703a2f2f63726c2e6c626f726f2e61632e756b2f63612d63726c2e70656d302106096086480186f842010d04141612436f6d707574696e67205365727669636573301106096086480186f842010104040302064030130603551d25040c300a06082b06010505070301300d06092a864886f70d010104050003818100
EAP-Message = 0xa46e005a7d7653dd96c94d97
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xf8bf8318f9a49a932e088bdf9b3f173d
Finished request 132.
Going to the next request
Waking up in 0.5 seconds.
rad_recv: Access-Request packet from host 10.5.9.101 port 1812, id=129, length=167
NAS-IP-Address = 10.5.9.101
NAS-Port = 50016
Cisco-NAS-Port = "FastEthernet0/16"
NAS-Port-Type = Ethernet
User-Name = "test-printer"
Called-Station-Id = "00-0E-D7-74-D1-10"
Calling-Station-Id = "00-1F-29-23-BA-41"
Service-Type = Framed-User
Framed-MTU = 1500
State = 0xf8bf8318f9a49a932e088bdf9b3f173d
EAP-Message = 0x021b00061900
Message-Authenticator = 0x21bae6c51ca6bf92764e8919c3249bc8
+- entering group authorize {...}
[preprocess] expand: %{Client-IP-Address} -> 10.5.9.101
[preprocess] expand: %{Client-IP-Address} -> 10.5.9.101
[preprocess] expand: %{Client-IP-Address} -> 10.5.9.101
++[preprocess] returns ok
[suffix] No '@' in User-Name = "test-printer", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[ntdomain] No '\' in User-Name = "test-printer", looking up realm NULL
[ntdomain] No such realm "NULL"
++[ntdomain] returns noop
++? if ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/)
expand: %{User-Name} -> test-printer
? Evaluating ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/) -> TRUE
++? if ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/) -> TRUE
++- entering if ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/) {...}
+++? if (!"%{2}" || ("%{2}" == "realm.org") || ("%{2}" == "realm.com") )
expand: %{2} ->
? Evaluating !("%{2}" ) -> FALSE
? Skipping ("%{2}" == "realm.org")
? Skipping ("%{2}" == "realm.com")
+++? if (!"%{2}" || ("%{2}" == "realm.org") || ("%{2}" == "realm.com") ) -> TRUE
+++- entering if (!"%{2}" || ("%{2}" == "realm.org") || ("%{2}" == "realm.com") ) {...}
++++[request] returns noop
+++- if (!"%{2}" || ("%{2}" == "realm.org") || ("%{2}" == "realm.com") ) returns noop
+++ ... skipping else for request 133: Preceding "if" was taken
++- if ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/) returns noop
++ ... skipping else for request 133: Preceding "if" was taken
++? if ("%{Called-Station-Id}" =~ /.*:testssid$/ || "%{NAS-IP-Address}" =~ /10.5\.2\.[2|3|5|6|7]$/ )
expand: %{Called-Station-Id} -> 00-0E-D7-74-D1-10
? Evaluating ("%{Called-Station-Id}" =~ /.*:testssid$/) -> FALSE
expand: %{NAS-IP-Address} -> 10.5.9.101
Evaluating ("%{NAS-IP-Address}" =~ /10.5\.2\.[2|3|5|6|7]$/) -> FALSE
++? if ("%{Called-Station-Id}" =~ /.*:testssid$/ || "%{NAS-IP-Address}" =~ /10.5\.2\.[2|3|5|6|7]$/ ) -> FALSE
expand: %{Realm} -> local
++- entering switch %{Realm} {...}
+++- entering case local {...}
++++- case local returns notfound
+++- switch %{Realm} returns notfound
++- switch %{Realm} returns notfound
add-dollar-sign: Could not find value pair for attribute Stripped-User-Name
++[add-dollar-sign] returns noop
strip-realm-name: Could not find value pair for attribute Stripped-User-Name
++[strip-realm-name] returns noop
remove-lboro: Could not find value pair for attribute Stripped-User-Name
++[remove-lboro] returns noop
[auth_log] expand: /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/radius/radacct/10.5.9.101/auth-detail-20090113
[auth_log] /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/radius/radacct/10.5.9.101/auth-detail-20090113
[auth_log] expand: %t -> Tue Jan 13 12:11:21 2009
++[auth_log] returns ok
++[mschap] returns noop
[eap] EAP packet type response id 27 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 129 to 10.5.9.101 port 1812
EAP-Message = 0x011c03c51900fd8b8b1442f059168ce5789c4df66d54eb775cfe263f988c2615bfb4aa699a1044ef4753f477b224dc5c42f607685092d9f2aff5c369c03137b031b3a08ac35074301f967418bfb77a7cd41c64452aeccab02053fe837216f541a9c848c284190eb8c589144ef2d1c1463a57a27b0d4fda0d001900033f3082033b308202a4020100300d06092a864886f70d01010405003081e5310b3009060355040613024742311730150603550408130e4c65696365737465727368697265311530130603550407130c4c6f756768626f726f7567683120301e060355040a13174c6f756768626f726f75676820556e6976657273697479311b3019
EAP-Message = 0x060355040b1312436f6d707574696e67205365727669636573313630340603550403132d4c6f756768626f726f75676820556e697665727369747920436572746966696361746520417574686f72697479312f302d06092a864886f70d01090116204365727469666963617465417574686f72697479406c626f726f2e61632e756b301e170d3938303831393134333435345a170d3139313233313134333435345a3081e5310b3009060355040613024742311730150603550408130e4c65696365737465727368697265311530130603550407130c4c6f756768626f726f7567683120301e060355040a13174c6f756768626f726f75676820556e69
EAP-Message = 0x76657273697479311b3019060355040b1312436f6d707574696e67205365727669636573313630340603550403132d4c6f756768626f726f75676820556e697665727369747920436572746966696361746520417574686f72697479312f302d06092a864886f70d01090116204365727469666963617465417574686f72697479406c626f726f2e61632e756b30819f300d06092a864886f70d010101050003818d0030818902818100a79af8b26aef34952ce192442557a63755f115d1d45396a93d59bdff479f126fa56fb397e522f0b80fc66825688ae0c40823dc3d9d6c6f4caf5c0b346e05a20e044be0afe2f589ee0c581cd772c9dbc34795d4
EAP-Message = 0x0a15a6df4c9c6ca84c7a3021b027a2770db3baf1574331d4d1934ef97fb5d701fca31f57a8a4a90df5d56bc55d0203010001300d06092a864886f70d010104050003818100204f5bccc5dec874e0a74098aa417367f3607c68e303ee25c4e9c7b024109031aff457a38fa5a0a87b0ce09634da45aad16f11db7a3947d4e2c189f38257ca628acbf3973cd2b99343c78c8fdb9d2fa6ff4999c516eb98d9e5a0cba7dd6573cdddf2e7b40342996a650699e2983b8c777340f268bea8dff044171793947a3f7d16030100040e000000
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xf8bf8318faa39a932e088bdf9b3f173d
Finished request 133.
Going to the next request
Waking up in 0.4 seconds.
rad_recv: Access-Request packet from host 10.5.9.101 port 1812, id=130, length=491
NAS-IP-Address = 10.5.9.101
NAS-Port = 50016
Cisco-NAS-Port = "FastEthernet0/16"
NAS-Port-Type = Ethernet
User-Name = "test-printer"
Called-Station-Id = "00-0E-D7-74-D1-10"
Calling-Station-Id = "00-1F-29-23-BA-41"
Service-Type = Framed-User
Framed-MTU = 1500
State = 0xf8bf8318faa39a932e088bdf9b3f173d
EAP-Message = 0x021c014819800000013e1603010106100001020100b00310558dd5fe9e408c7fa8bf0f7badb5806a0f0681889e4aa4f121cc54b237c027ef2ba9583367e6a9fce2e5746b251e5ade976a9182520dc24ace5263409fdaa70d44ce7adb49b0238891bd1bb5b96b72dae90cd270815d2fb7da7273d9c31e64a2d89cd158ebf02852cbdaa6574cd3cf348455de5259fc2329f373a5328eec904a47f8cc06c7052268c818031ab2f8cab150c947ad5b08fd63bff61ee39f8a850d03e7188d4a3a31ce6e0c9a12de0d3f645e00f2125e29a083489bc11a6f44f2fe1c57c38838d284b152bd391d7a93012c1c77269234225fe26c7b4f2491a23486e47eb3d89c
EAP-Message = 0x4c65c58ed14ae8f0e260b48cea3309b0c311521028be55031403010001011603010028c89c6de2d05ef14fb2f4c6b0412edfa77dcdeacdd4d3316e57611e44ca70f3d3ae4974c507b3e0da
Message-Authenticator = 0x1b785262624fe08ad962b8869b093dc7
+- entering group authorize {...}
[preprocess] expand: %{Client-IP-Address} -> 10.5.9.101
[preprocess] expand: %{Client-IP-Address} -> 10.5.9.101
[preprocess] expand: %{Client-IP-Address} -> 10.5.9.101
++[preprocess] returns ok
[suffix] No '@' in User-Name = "test-printer", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[ntdomain] No '\' in User-Name = "test-printer", looking up realm NULL
[ntdomain] No such realm "NULL"
++[ntdomain] returns noop
++? if ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/)
expand: %{User-Name} -> test-printer
? Evaluating ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/) -> TRUE
++? if ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/) -> TRUE
++- entering if ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/) {...}
+++? if (!"%{2}" || ("%{2}" == "realm.org") || ("%{2}" == "realm.com") )
expand: %{2} ->
? Evaluating !("%{2}" ) -> FALSE
? Skipping ("%{2}" == "realm.org")
? Skipping ("%{2}" == "realm.com")
+++? if (!"%{2}" || ("%{2}" == "realm.org") || ("%{2}" == "realm.com") ) -> TRUE
+++- entering if (!"%{2}" || ("%{2}" == "realm.org") || ("%{2}" == "realm.com") ) {...}
++++[request] returns noop
+++- if (!"%{2}" || ("%{2}" == "realm.org") || ("%{2}" == "realm.com") ) returns noop
+++ ... skipping else for request 134: Preceding "if" was taken
++- if ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/) returns noop
++ ... skipping else for request 134: Preceding "if" was taken
++? if ("%{Called-Station-Id}" =~ /.*:testssid$/ || "%{NAS-IP-Address}" =~ /10.5\.2\.[2|3|5|6|7]$/ )
expand: %{Called-Station-Id} -> 00-0E-D7-74-D1-10
? Evaluating ("%{Called-Station-Id}" =~ /.*:testssid$/) -> FALSE
expand: %{NAS-IP-Address} -> 10.5.9.101
Evaluating ("%{NAS-IP-Address}" =~ /10.5\.2\.[2|3|5|6|7]$/) -> FALSE
++? if ("%{Called-Station-Id}" =~ /.*:testssid$/ || "%{NAS-IP-Address}" =~ /10.5\.2\.[2|3|5|6|7]$/ ) -> FALSE
expand: %{Realm} -> local
++- entering switch %{Realm} {...}
+++- entering case local {...}
++++- case local returns notfound
+++- switch %{Realm} returns notfound
++- switch %{Realm} returns notfound
add-dollar-sign: Could not find value pair for attribute Stripped-User-Name
++[add-dollar-sign] returns noop
strip-realm-name: Could not find value pair for attribute Stripped-User-Name
++[strip-realm-name] returns noop
remove-lboro: Could not find value pair for attribute Stripped-User-Name
++[remove-lboro] returns noop
[auth_log] expand: /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/radius/radacct/10.5.9.101/auth-detail-20090113
[auth_log] /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/radius/radacct/10.5.9.101/auth-detail-20090113
[auth_log] expand: %t -> Tue Jan 13 12:11:21 2009
++[auth_log] returns ok
++[mschap] returns noop
[eap] EAP packet type response id 28 length 253
[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 318
[peap] Length Included
[peap] eaptls_verify returned 11
[peap] <<< TLS 1.0 Handshake [length 0106], ClientKeyExchange
[peap] TLS_accept: SSLv3 read client key exchange A
[peap] <<< TLS 1.0 ChangeCipherSpec [length 0001]
[peap] <<< TLS 1.0 Handshake [length 0010], Finished
[peap] TLS_accept: SSLv3 read finished A
[peap] >>> TLS 1.0 ChangeCipherSpec [length 0001]
[peap] TLS_accept: SSLv3 write change cipher spec A
[peap] >>> TLS 1.0 Handshake [length 0010], Finished
[peap] TLS_accept: SSLv3 write finished A
[peap] TLS_accept: SSLv3 flush data
[peap] (other): SSL negotiation finished successfully
SSL Connection Established
[peap] eaptls_process returned 13
[peap] EAPTLS_HANDLED
++[eap] returns handled
Sending Access-Challenge of id 130 to 10.5.9.101 port 1812
EAP-Message = 0x011d00391900140301000101160301002869a54190128735d29a4bbe6c19e69da0eaaafa9a37bb4317fd1330d1b0b163652593369a8cc5c656
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xf8bf8318fba29a932e088bdf9b3f173d
Finished request 134.
Going to the next request
Waking up in 0.3 seconds.
rad_recv: Access-Request packet from host 10.5.9.101 port 1812, id=131, length=167
NAS-IP-Address = 10.5.9.101
NAS-Port = 50016
Cisco-NAS-Port = "FastEthernet0/16"
NAS-Port-Type = Ethernet
User-Name = "test-printer"
Called-Station-Id = "00-0E-D7-74-D1-10"
Calling-Station-Id = "00-1F-29-23-BA-41"
Service-Type = Framed-User
Framed-MTU = 1500
State = 0xf8bf8318fba29a932e088bdf9b3f173d
EAP-Message = 0x021d00061900
Message-Authenticator = 0xfeea83d6bf619c46035700ae8ea1ffc7
+- entering group authorize {...}
[preprocess] expand: %{Client-IP-Address} -> 10.5.9.101
[preprocess] expand: %{Client-IP-Address} -> 10.5.9.101
[preprocess] expand: %{Client-IP-Address} -> 10.5.9.101
++[preprocess] returns ok
[suffix] No '@' in User-Name = "test-printer", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[ntdomain] No '\' in User-Name = "test-printer", looking up realm NULL
[ntdomain] No such realm "NULL"
++[ntdomain] returns noop
++? if ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/)
expand: %{User-Name} -> test-printer
? Evaluating ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/) -> TRUE
++? if ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/) -> TRUE
++- entering if ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/) {...}
+++? if (!"%{2}" || ("%{2}" == "realm.org") || ("%{2}" == "realm.com") )
expand: %{2} ->
? Evaluating !("%{2}" ) -> FALSE
? Skipping ("%{2}" == "realm.org")
? Skipping ("%{2}" == "realm.com")
+++? if (!"%{2}" || ("%{2}" == "realm.org") || ("%{2}" == "realm.com") ) -> TRUE
+++- entering if (!"%{2}" || ("%{2}" == "realm.org") || ("%{2}" == "realm.com") ) {...}
++++[request] returns noop
+++- if (!"%{2}" || ("%{2}" == "realm.org") || ("%{2}" == "realm.com") ) returns noop
+++ ... skipping else for request 135: Preceding "if" was taken
++- if ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/) returns noop
++ ... skipping else for request 135: Preceding "if" was taken
++? if ("%{Called-Station-Id}" =~ /.*:testssid$/ || "%{NAS-IP-Address}" =~ /10.5\.2\.[2|3|5|6|7]$/ )
expand: %{Called-Station-Id} -> 00-0E-D7-74-D1-10
? Evaluating ("%{Called-Station-Id}" =~ /.*:testssid$/) -> FALSE
expand: %{NAS-IP-Address} -> 10.5.9.101
Evaluating ("%{NAS-IP-Address}" =~ /10.5\.2\.[2|3|5|6|7]$/) -> FALSE
++? if ("%{Called-Station-Id}" =~ /.*:testssid$/ || "%{NAS-IP-Address}" =~ /10.5\.2\.[2|3|5|6|7]$/ ) -> FALSE
expand: %{Realm} -> local
++- entering switch %{Realm} {...}
+++- entering case local {...}
++++- case local returns notfound
+++- switch %{Realm} returns notfound
++- switch %{Realm} returns notfound
add-dollar-sign: Could not find value pair for attribute Stripped-User-Name
++[add-dollar-sign] returns noop
strip-realm-name: Could not find value pair for attribute Stripped-User-Name
++[strip-realm-name] returns noop
remove-lboro: Could not find value pair for attribute Stripped-User-Name
++[remove-lboro] returns noop
[auth_log] expand: /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/radius/radacct/10.5.9.101/auth-detail-20090113
[auth_log] /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/radius/radacct/10.5.9.101/auth-detail-20090113
[auth_log] expand: %t -> Tue Jan 13 12:11:21 2009
++[auth_log] returns ok
++[mschap] returns noop
[eap] EAP packet type response id 29 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 131 to 10.5.9.101 port 1812
EAP-Message = 0x011e002b1900170301002057f605190d599fb9d49e7d6bba23ed713cf450f4e57c56a9fc125bdeb8155529
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xf8bf8318fca19a932e088bdf9b3f173d
Finished request 135.
Going to the next request
Waking up in 0.3 seconds.
rad_recv: Access-Request packet from host 10.5.9.101 port 1812, id=132, length=241
NAS-IP-Address = 10.5.9.101
NAS-Port = 50016
Cisco-NAS-Port = "FastEthernet0/16"
NAS-Port-Type = Ethernet
User-Name = "test-printer"
Called-Station-Id = "00-0E-D7-74-D1-10"
Calling-Station-Id = "00-1F-29-23-BA-41"
Service-Type = Framed-User
Framed-MTU = 1500
State = 0xf8bf8318fca19a932e088bdf9b3f173d
EAP-Message = 0x021e0050190017030100187d7e4b29f7d9d05961f1f042e4ab7760282bd694428faf37170301002883616832297d2e158912d6f3778ebdae5161d36ad0936c2597608acc557f96f232544f4a64ac554c
Message-Authenticator = 0x4d2528d31ea8ab74aabed3e24558ab3e
+- entering group authorize {...}
[preprocess] expand: %{Client-IP-Address} -> 10.5.9.101
[preprocess] expand: %{Client-IP-Address} -> 10.5.9.101
[preprocess] expand: %{Client-IP-Address} -> 10.5.9.101
++[preprocess] returns ok
[suffix] No '@' in User-Name = "test-printer", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[ntdomain] No '\' in User-Name = "test-printer", looking up realm NULL
[ntdomain] No such realm "NULL"
++[ntdomain] returns noop
++? if ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/)
expand: %{User-Name} -> test-printer
? Evaluating ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/) -> TRUE
++? if ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/) -> TRUE
++- entering if ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/) {...}
+++? if (!"%{2}" || ("%{2}" == "realm.org") || ("%{2}" == "realm.com") )
expand: %{2} ->
? Evaluating !("%{2}" ) -> FALSE
? Skipping ("%{2}" == "realm.org")
? Skipping ("%{2}" == "realm.com")
+++? if (!"%{2}" || ("%{2}" == "realm.org") || ("%{2}" == "realm.com") ) -> TRUE
+++- entering if (!"%{2}" || ("%{2}" == "realm.org") || ("%{2}" == "realm.com") ) {...}
++++[request] returns noop
+++- if (!"%{2}" || ("%{2}" == "realm.org") || ("%{2}" == "realm.com") ) returns noop
+++ ... skipping else for request 136: Preceding "if" was taken
++- if ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/) returns noop
++ ... skipping else for request 136: Preceding "if" was taken
++? if ("%{Called-Station-Id}" =~ /.*:testssid$/ || "%{NAS-IP-Address}" =~ /10.5\.2\.[2|3|5|6|7]$/ )
expand: %{Called-Station-Id} -> 00-0E-D7-74-D1-10
? Evaluating ("%{Called-Station-Id}" =~ /.*:testssid$/) -> FALSE
expand: %{NAS-IP-Address} -> 10.5.9.101
Evaluating ("%{NAS-IP-Address}" =~ /10.5\.2\.[2|3|5|6|7]$/) -> FALSE
++? if ("%{Called-Station-Id}" =~ /.*:testssid$/ || "%{NAS-IP-Address}" =~ /10.5\.2\.[2|3|5|6|7]$/ ) -> FALSE
expand: %{Realm} -> local
++- entering switch %{Realm} {...}
+++- entering case local {...}
++++- case local returns notfound
+++- switch %{Realm} returns notfound
++- switch %{Realm} returns notfound
add-dollar-sign: Could not find value pair for attribute Stripped-User-Name
++[add-dollar-sign] returns noop
strip-realm-name: Could not find value pair for attribute Stripped-User-Name
++[strip-realm-name] returns noop
remove-lboro: Could not find value pair for attribute Stripped-User-Name
++[remove-lboro] returns noop
[auth_log] expand: /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/radius/radacct/10.5.9.101/auth-detail-20090113
[auth_log] /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/radius/radacct/10.5.9.101/auth-detail-20090113
[auth_log] expand: %t -> Tue Jan 13 12:11:21 2009
++[auth_log] returns ok
++[mschap] returns noop
[eap] EAP packet type response id 30 length 80
[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] Got something weird.
[peap] Tunneled data is invalid.
[eap] Handler failed in EAP/peap
[eap] Failed in EAP select
++[eap] returns invalid
Failed to authenticate the user.
Login incorrect: [test-printer] (from client Cisco-AP port 50016 cli 00-1F-29-23-BA-41)
Using Post-Auth-Type Reject
+- entering group REJECT {...}
[attr_filter.access_reject] expand: %{User-Name} -> test-printer
attr_filter: Matched entry DEFAULT at line 11
++[attr_filter.access_reject] returns updated
Delaying reject of request 136 for 1 seconds
Going to the next request
Waking up in 0.2 seconds.
Cleaning up request 125 ID 121 with timestamp +1534
Cleaning up request 126 ID 122 with timestamp +1534
Cleaning up request 127 ID 123 with timestamp +1534
Waking up in 0.1 seconds.
Cleaning up request 128 ID 124 with timestamp +1534
Cleaning up request 129 ID 125 with timestamp +1535
Waking up in 0.4 seconds.
Sending delayed reject for request 136
Sending Access-Reject of id 132 to 10.5.9.101 port 1812
EAP-Message = 0x041e0004
Message-Authenticator = 0x00000000000000000000000000000000
Waking up in 0.6 seconds.
rad_recv: Access-Request packet from host 10.5.9.101 port 1812, id=133, length=157
NAS-IP-Address = 10.5.9.101
NAS-Port = 50016
Cisco-NAS-Port = "FastEthernet0/16"
NAS-Port-Type = Ethernet
User-Name = "test-printer"
Called-Station-Id = "00-0E-D7-74-D1-10"
Calling-Station-Id = "00-1F-29-23-BA-41"
Service-Type = Framed-User
Framed-MTU = 1500
EAP-Message = 0x021f000e0163637072696e746572
Message-Authenticator = 0x274f7abf18fcaaa396b8484492e4fff0
+- entering group authorize {...}
[preprocess] expand: %{Client-IP-Address} -> 10.5.9.101
[preprocess] expand: %{Client-IP-Address} -> 10.5.9.101
[preprocess] expand: %{Client-IP-Address} -> 10.5.9.101
++[preprocess] returns ok
[suffix] No '@' in User-Name = "test-printer", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[ntdomain] No '\' in User-Name = "test-printer", looking up realm NULL
[ntdomain] No such realm "NULL"
++[ntdomain] returns noop
++? if ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/)
expand: %{User-Name} -> test-printer
? Evaluating ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/) -> TRUE
++? if ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/) -> TRUE
++- entering if ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/) {...}
+++? if (!"%{2}" || ("%{2}" == "realm.org") || ("%{2}" == "realm.com") )
expand: %{2} ->
? Evaluating !("%{2}" ) -> FALSE
? Skipping ("%{2}" == "realm.org")
? Skipping ("%{2}" == "realm.com")
+++? if (!"%{2}" || ("%{2}" == "realm.org") || ("%{2}" == "realm.com") ) -> TRUE
+++- entering if (!"%{2}" || ("%{2}" == "realm.org") || ("%{2}" == "realm.com") ) {...}
++++[request] returns noop
+++- if (!"%{2}" || ("%{2}" == "realm.org") || ("%{2}" == "realm.com") ) returns noop
+++ ... skipping else for request 137: Preceding "if" was taken
++- if ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/) returns noop
++ ... skipping else for request 137: Preceding "if" was taken
++? if ("%{Called-Station-Id}" =~ /.*:testssid$/ || "%{NAS-IP-Address}" =~ /10.5\.2\.[2|3|5|6|7]$/ )
expand: %{Called-Station-Id} -> 00-0E-D7-74-D1-10
? Evaluating ("%{Called-Station-Id}" =~ /.*:testssid$/) -> FALSE
expand: %{NAS-IP-Address} -> 10.5.9.101
Evaluating ("%{NAS-IP-Address}" =~ /10.5\.2\.[2|3|5|6|7]$/) -> FALSE
++? if ("%{Called-Station-Id}" =~ /.*:testssid$/ || "%{NAS-IP-Address}" =~ /10.5\.2\.[2|3|5|6|7]$/ ) -> FALSE
expand: %{Realm} -> local
++- entering switch %{Realm} {...}
+++- entering case local {...}
++++- case local returns notfound
+++- switch %{Realm} returns notfound
++- switch %{Realm} returns notfound
add-dollar-sign: Could not find value pair for attribute Stripped-User-Name
++[add-dollar-sign] returns noop
strip-realm-name: Could not find value pair for attribute Stripped-User-Name
++[strip-realm-name] returns noop
remove-lboro: Could not find value pair for attribute Stripped-User-Name
++[remove-lboro] returns noop
[auth_log] expand: /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/radius/radacct/10.5.9.101/auth-detail-20090113
[auth_log] /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/radius/radacct/10.5.9.101/auth-detail-20090113
[auth_log] expand: %t -> Tue Jan 13 12:11:22 2009
++[auth_log] returns ok
++[mschap] returns noop
[eap] EAP packet type response id 31 length 14
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
[files] users: Matched entry DEFAULT at line 168
++[files] returns ok
[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] Initiate
[tls] Start returned 1
++[eap] returns handled
Sending Access-Challenge of id 133 to 10.5.9.101 port 1812
EAP-Message = 0x012000061920
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xc6470902c667104f0da0a4cab4725122
Finished request 137.
Going to the next request
Waking up in 0.5 seconds.
rad_recv: Access-Request packet from host 10.5.9.101 port 1812, id=134, length=227
NAS-IP-Address = 10.5.9.101
NAS-Port = 50016
Cisco-NAS-Port = "FastEthernet0/16"
NAS-Port-Type = Ethernet
User-Name = "test-printer"
Called-Station-Id = "00-0E-D7-74-D1-10"
Calling-Station-Id = "00-1F-29-23-BA-41"
Service-Type = Framed-User
Framed-MTU = 1500
State = 0xc6470902c667104f0da0a4cab4725122
EAP-Message = 0x0220004219800000003816030100330100002f030100000074f58996628f8b58c3d954eb2a31613acf6036a5c0c7d4d7217963e119000008000a0005000400090100
Message-Authenticator = 0x64f42314d76889fa90d42fea02015a0f
+- entering group authorize {...}
[preprocess] expand: %{Client-IP-Address} -> 10.5.9.101
[preprocess] expand: %{Client-IP-Address} -> 10.5.9.101
[preprocess] expand: %{Client-IP-Address} -> 10.5.9.101
++[preprocess] returns ok
[suffix] No '@' in User-Name = "test-printer", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[ntdomain] No '\' in User-Name = "test-printer", looking up realm NULL
[ntdomain] No such realm "NULL"
++[ntdomain] returns noop
++? if ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/)
expand: %{User-Name} -> test-printer
? Evaluating ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/) -> TRUE
++? if ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/) -> TRUE
++- entering if ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/) {...}
+++? if (!"%{2}" || ("%{2}" == "realm.org") || ("%{2}" == "realm.com") )
expand: %{2} ->
? Evaluating !("%{2}" ) -> FALSE
? Skipping ("%{2}" == "realm.org")
? Skipping ("%{2}" == "realm.com")
+++? if (!"%{2}" || ("%{2}" == "realm.org") || ("%{2}" == "realm.com") ) -> TRUE
+++- entering if (!"%{2}" || ("%{2}" == "realm.org") || ("%{2}" == "realm.com") ) {...}
++++[request] returns noop
+++- if (!"%{2}" || ("%{2}" == "realm.org") || ("%{2}" == "realm.com") ) returns noop
+++ ... skipping else for request 138: Preceding "if" was taken
++- if ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/) returns noop
++ ... skipping else for request 138: Preceding "if" was taken
++? if ("%{Called-Station-Id}" =~ /.*:testssid$/ || "%{NAS-IP-Address}" =~ /10.5\.2\.[2|3|5|6|7]$/ )
expand: %{Called-Station-Id} -> 00-0E-D7-74-D1-10
? Evaluating ("%{Called-Station-Id}" =~ /.*:testssid$/) -> FALSE
expand: %{NAS-IP-Address} -> 10.5.9.101
Evaluating ("%{NAS-IP-Address}" =~ /10.5\.2\.[2|3|5|6|7]$/) -> FALSE
++? if ("%{Called-Station-Id}" =~ /.*:testssid$/ || "%{NAS-IP-Address}" =~ /10.5\.2\.[2|3|5|6|7]$/ ) -> FALSE
expand: %{Realm} -> local
++- entering switch %{Realm} {...}
+++- entering case local {...}
++++- case local returns notfound
+++- switch %{Realm} returns notfound
++- switch %{Realm} returns notfound
add-dollar-sign: Could not find value pair for attribute Stripped-User-Name
++[add-dollar-sign] returns noop
strip-realm-name: Could not find value pair for attribute Stripped-User-Name
++[strip-realm-name] returns noop
remove-lboro: Could not find value pair for attribute Stripped-User-Name
++[remove-lboro] returns noop
[auth_log] expand: /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/radius/radacct/10.5.9.101/auth-detail-20090113
[auth_log] /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/radius/radacct/10.5.9.101/auth-detail-20090113
[auth_log] expand: %t -> Tue Jan 13 12:11:22 2009
++[auth_log] returns ok
++[mschap] returns noop
[eap] EAP packet type response id 32 length 66
[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 56
[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 0033], ClientHello
[peap] TLS_accept: SSLv3 read client hello A
[peap] >>> TLS 1.0 Handshake [length 002a], ServerHello
[peap] TLS_accept: SSLv3 write server hello A
[peap] >>> TLS 1.0 Handshake [length 0778], Certificate
[peap] TLS_accept: SSLv3 write certificate A
[peap] >>> TLS 1.0 Handshake [length 0004], ServerHelloDone
[peap] TLS_accept: SSLv3 write server done A
[peap] TLS_accept: SSLv3 flush data
[peap] TLS_accept: Need to read more data: SSLv3 read client certificate A
In SSL Handshake Phase
In SSL Accept mode
[peap] eaptls_process returned 13
[peap] EAPTLS_HANDLED
++[eap] returns handled
Sending Access-Challenge of id 134 to 10.5.9.101 port 1812
EAP-Message = 0x0121040019c0000007b5160301002a020000260301496c84eadcb4b41a909e0055f7c1f2fa2bb5069c718d0f1897938fd738b3f91300000a0016030107780b00077400077100042c3082042830820391a00302010202015e300d06092a864886f70d01010405003081e5310b3009060355040613024742311730150603550408130e4c65696365737465727368697265311530130603550407130c4c6f756768626f726f7567683120301e060355040a13174c6f756768626f726f75676820556e6976657273697479311b3019060355040b1312436f6d707574696e67205365727669636573313630340603550403132d4c6f756768626f726f756768
EAP-Message = 0x20556e697665727369747920436572746966696361746520417574686f72697479312f302d06092a864886f70d01090116204365727469666963617465417574686f72697479406c626f726f2e61632e756b301e170d3036303730333136313034375a170d3132303833313136313034375a3081c8310b3009060355040613024742311730150603550408130e4c65696365737465727368697265311530130603550407130c4c6f756768626f726f7567683120301e060355040a13174c6f756768626f726f75676820556e6976657273697479311b3019060355040b1312436f6d707574696e67205365727669636573311b30190603550403131272
EAP-Message = 0x61646975732e6c626f726f2e61632e756b312d302b06092a864886f70d010901161e636f6d707574696e672e7365727669636573406c626f726f2e61632e756b30820122300d06092a864886f70d01010105000382010f003082010a0282010100c4ba691d26b4bc2ae2bd7d9e8be96868ed2c919944e3a837eaeacd4ca3d8ce8d2686ab1f62470ae672a070e51a96a95d01d6a0a583dd4cf5d98f171e85887afe91981f95fff84d87fd40b32fbb2b29b47acd8a0223f691809e55321e3899978049b5e71ab5956f6b52838d1f408a56b80bf67edc70f234928a728f70707b62b7872a607da926dfbf111c991ce576fac4a07e3cae01f27f3dc539ec93
EAP-Message = 0xd5f2f86867e54aa8e44db1630893e0f02ff29b57cc700fc90a469ff5da5c40296f5cfcd193a30054ff50c07bbd226e31a379df2406de43ae5fa0406a646e240d0682da21d4f1d3d0f578258f5422b37a699549c07787d56020367da70870985e8113f08f0203010001a37f307d303006096086480186f842010404231621687474703a2f2f63726c2e6c626f726f2e61632e756b2f63612d63726c2e70656d302106096086480186f842010d04141612436f6d707574696e67205365727669636573301106096086480186f842010104040302064030130603551d25040c300a06082b06010505070301300d06092a864886f70d010104050003818100
EAP-Message = 0xa46e005a7d7653dd96c94d97
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xc6470902c766104f0da0a4cab4725122
Finished request 138.
Going to the next request
Waking up in 0.5 seconds.
rad_recv: Access-Request packet from host 10.5.9.101 port 1812, id=135, length=167
NAS-IP-Address = 10.5.9.101
NAS-Port = 50016
Cisco-NAS-Port = "FastEthernet0/16"
NAS-Port-Type = Ethernet
User-Name = "test-printer"
Called-Station-Id = "00-0E-D7-74-D1-10"
Calling-Station-Id = "00-1F-29-23-BA-41"
Service-Type = Framed-User
Framed-MTU = 1500
State = 0xc6470902c766104f0da0a4cab4725122
EAP-Message = 0x022100061900
Message-Authenticator = 0xb7977141c7a8904682113352c8697bcf
+- entering group authorize {...}
[preprocess] expand: %{Client-IP-Address} -> 10.5.9.101
[preprocess] expand: %{Client-IP-Address} -> 10.5.9.101
[preprocess] expand: %{Client-IP-Address} -> 10.5.9.101
++[preprocess] returns ok
[suffix] No '@' in User-Name = "test-printer", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[ntdomain] No '\' in User-Name = "test-printer", looking up realm NULL
[ntdomain] No such realm "NULL"
++[ntdomain] returns noop
++? if ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/)
expand: %{User-Name} -> test-printer
? Evaluating ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/) -> TRUE
++? if ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/) -> TRUE
++- entering if ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/) {...}
+++? if (!"%{2}" || ("%{2}" == "realm.org") || ("%{2}" == "realm.com") )
expand: %{2} ->
? Evaluating !("%{2}" ) -> FALSE
? Skipping ("%{2}" == "realm.org")
? Skipping ("%{2}" == "realm.com")
+++? if (!"%{2}" || ("%{2}" == "realm.org") || ("%{2}" == "realm.com") ) -> TRUE
+++- entering if (!"%{2}" || ("%{2}" == "realm.org") || ("%{2}" == "realm.com") ) {...}
++++[request] returns noop
+++- if (!"%{2}" || ("%{2}" == "realm.org") || ("%{2}" == "realm.com") ) returns noop
+++ ... skipping else for request 139: Preceding "if" was taken
++- if ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/) returns noop
++ ... skipping else for request 139: Preceding "if" was taken
++? if ("%{Called-Station-Id}" =~ /.*:testssid$/ || "%{NAS-IP-Address}" =~ /10.5\.2\.[2|3|5|6|7]$/ )
expand: %{Called-Station-Id} -> 00-0E-D7-74-D1-10
? Evaluating ("%{Called-Station-Id}" =~ /.*:testssid$/) -> FALSE
expand: %{NAS-IP-Address} -> 10.5.9.101
Evaluating ("%{NAS-IP-Address}" =~ /10.5\.2\.[2|3|5|6|7]$/) -> FALSE
++? if ("%{Called-Station-Id}" =~ /.*:testssid$/ || "%{NAS-IP-Address}" =~ /10.5\.2\.[2|3|5|6|7]$/ ) -> FALSE
expand: %{Realm} -> local
++- entering switch %{Realm} {...}
+++- entering case local {...}
++++- case local returns notfound
+++- switch %{Realm} returns notfound
++- switch %{Realm} returns notfound
add-dollar-sign: Could not find value pair for attribute Stripped-User-Name
++[add-dollar-sign] returns noop
strip-realm-name: Could not find value pair for attribute Stripped-User-Name
++[strip-realm-name] returns noop
remove-lboro: Could not find value pair for attribute Stripped-User-Name
++[remove-lboro] returns noop
[auth_log] expand: /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/radius/radacct/10.5.9.101/auth-detail-20090113
[auth_log] /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/radius/radacct/10.5.9.101/auth-detail-20090113
[auth_log] expand: %t -> Tue Jan 13 12:11:22 2009
++[auth_log] returns ok
++[mschap] returns noop
[eap] EAP packet type response id 33 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 135 to 10.5.9.101 port 1812
EAP-Message = 0x012203c51900fd8b8b1442f059168ce5789c4df66d54eb775cfe263f988c2615bfb4aa699a1044ef4753f477b224dc5c42f607685092d9f2aff5c369c03137b031b3a08ac35074301f967418bfb77a7cd41c64452aeccab02053fe837216f541a9c848c284190eb8c589144ef2d1c1463a57a27b0d4fda0d001900033f3082033b308202a4020100300d06092a864886f70d01010405003081e5310b3009060355040613024742311730150603550408130e4c65696365737465727368697265311530130603550407130c4c6f756768626f726f7567683120301e060355040a13174c6f756768626f726f75676820556e6976657273697479311b3019
EAP-Message = 0x060355040b1312436f6d707574696e67205365727669636573313630340603550403132d4c6f756768626f726f75676820556e697665727369747920436572746966696361746520417574686f72697479312f302d06092a864886f70d01090116204365727469666963617465417574686f72697479406c626f726f2e61632e756b301e170d3938303831393134333435345a170d3139313233313134333435345a3081e5310b3009060355040613024742311730150603550408130e4c65696365737465727368697265311530130603550407130c4c6f756768626f726f7567683120301e060355040a13174c6f756768626f726f75676820556e69
EAP-Message = 0x76657273697479311b3019060355040b1312436f6d707574696e67205365727669636573313630340603550403132d4c6f756768626f726f75676820556e697665727369747920436572746966696361746520417574686f72697479312f302d06092a864886f70d01090116204365727469666963617465417574686f72697479406c626f726f2e61632e756b30819f300d06092a864886f70d010101050003818d0030818902818100a79af8b26aef34952ce192442557a63755f115d1d45396a93d59bdff479f126fa56fb397e522f0b80fc66825688ae0c40823dc3d9d6c6f4caf5c0b346e05a20e044be0afe2f589ee0c581cd772c9dbc34795d4
EAP-Message = 0x0a15a6df4c9c6ca84c7a3021b027a2770db3baf1574331d4d1934ef97fb5d701fca31f57a8a4a90df5d56bc55d0203010001300d06092a864886f70d010104050003818100204f5bccc5dec874e0a74098aa417367f3607c68e303ee25c4e9c7b024109031aff457a38fa5a0a87b0ce09634da45aad16f11db7a3947d4e2c189f38257ca628acbf3973cd2b99343c78c8fdb9d2fa6ff4999c516eb98d9e5a0cba7dd6573cdddf2e7b40342996a650699e2983b8c777340f268bea8dff044171793947a3f7d16030100040e000000
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xc6470902c465104f0da0a4cab4725122
Finished request 139.
Going to the next request
Waking up in 0.4 seconds.
rad_recv: Access-Request packet from host 10.5.9.101 port 1812, id=136, length=491
NAS-IP-Address = 10.5.9.101
NAS-Port = 50016
Cisco-NAS-Port = "FastEthernet0/16"
NAS-Port-Type = Ethernet
User-Name = "test-printer"
Called-Station-Id = "00-0E-D7-74-D1-10"
Calling-Station-Id = "00-1F-29-23-BA-41"
Service-Type = Framed-User
Framed-MTU = 1500
State = 0xc6470902c465104f0da0a4cab4725122
EAP-Message = 0x0222014819800000013e16030101061000010201001ea1500164c67b4a364723723dbbc86c5f7eede081d2c9002579ed4bcdca60367289cdd191b582a1edb47be65dae8f814d5fd08328373be8a361604f034bf6f880ac95026ff144695988b20e677f50730db40d0testssided872a2da99317dd40d0978b790760923638f456340ccb3b45f1d89540e97f97dbbe14c8cdc237fafaf35661fc2fb1726f967c4455a3bce0dd540df03e3d3fe56fb0ee1b7629814f51f11b37ca7565dd33fa553ab327510e4015a396ef518a08bd4a0e1acf32f27ff170cc4b4e28160f6ad0636e2d9b8cc05ea74ec18469750ec2b43fa0f47df6a115dcad8714bc7ebabaa6ca
EAP-Message = 0x69da3224af084b186f9d3e392694e2cde0f6f3b7c3518ef314030100010116030100281b448aff0a335f50d47055da8162249b0c75d52b01f6026de617f86153c31cd6f325258214ca11cb
Message-Authenticator = 0xa1c5fbe6075e0c5e3dfcfaca444ddadc
+- entering group authorize {...}
[preprocess] expand: %{Client-IP-Address} -> 10.5.9.101
[preprocess] expand: %{Client-IP-Address} -> 10.5.9.101
[preprocess] expand: %{Client-IP-Address} -> 10.5.9.101
++[preprocess] returns ok
[suffix] No '@' in User-Name = "test-printer", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[ntdomain] No '\' in User-Name = "test-printer", looking up realm NULL
[ntdomain] No such realm "NULL"
++[ntdomain] returns noop
++? if ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/)
expand: %{User-Name} -> test-printer
? Evaluating ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/) -> TRUE
++? if ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/) -> TRUE
++- entering if ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/) {...}
+++? if (!"%{2}" || ("%{2}" == "realm.org") || ("%{2}" == "realm.com") )
expand: %{2} ->
? Evaluating !("%{2}" ) -> FALSE
? Skipping ("%{2}" == "realm.org")
? Skipping ("%{2}" == "realm.com")
+++? if (!"%{2}" || ("%{2}" == "realm.org") || ("%{2}" == "realm.com") ) -> TRUE
+++- entering if (!"%{2}" || ("%{2}" == "realm.org") || ("%{2}" == "realm.com") ) {...}
++++[request] returns noop
+++- if (!"%{2}" || ("%{2}" == "realm.org") || ("%{2}" == "realm.com") ) returns noop
+++ ... skipping else for request 140: Preceding "if" was taken
++- if ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/) returns noop
++ ... skipping else for request 140: Preceding "if" was taken
++? if ("%{Called-Station-Id}" =~ /.*:testssid$/ || "%{NAS-IP-Address}" =~ /10.5\.2\.[2|3|5|6|7]$/ )
expand: %{Called-Station-Id} -> 00-0E-D7-74-D1-10
? Evaluating ("%{Called-Station-Id}" =~ /.*:testssid$/) -> FALSE
expand: %{NAS-IP-Address} -> 10.5.9.101
Evaluating ("%{NAS-IP-Address}" =~ /10.5\.2\.[2|3|5|6|7]$/) -> FALSE
++? if ("%{Called-Station-Id}" =~ /.*:testssid$/ || "%{NAS-IP-Address}" =~ /10.5\.2\.[2|3|5|6|7]$/ ) -> FALSE
expand: %{Realm} -> local
++- entering switch %{Realm} {...}
+++- entering case local {...}
++++- case local returns notfound
+++- switch %{Realm} returns notfound
++- switch %{Realm} returns notfound
add-dollar-sign: Could not find value pair for attribute Stripped-User-Name
++[add-dollar-sign] returns noop
strip-realm-name: Could not find value pair for attribute Stripped-User-Name
++[strip-realm-name] returns noop
remove-lboro: Could not find value pair for attribute Stripped-User-Name
++[remove-lboro] returns noop
[auth_log] expand: /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/radius/radacct/10.5.9.101/auth-detail-20090113
[auth_log] /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/radius/radacct/10.5.9.101/auth-detail-20090113
[auth_log] expand: %t -> Tue Jan 13 12:11:22 2009
++[auth_log] returns ok
++[mschap] returns noop
[eap] EAP packet type response id 34 length 253
[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 318
[peap] Length Included
[peap] eaptls_verify returned 11
[peap] <<< TLS 1.0 Handshake [length 0106], ClientKeyExchange
[peap] TLS_accept: SSLv3 read client key exchange A
[peap] <<< TLS 1.0 ChangeCipherSpec [length 0001]
[peap] <<< TLS 1.0 Handshake [length 0010], Finished
[peap] TLS_accept: SSLv3 read finished A
[peap] >>> TLS 1.0 ChangeCipherSpec [length 0001]
[peap] TLS_accept: SSLv3 write change cipher spec A
[peap] >>> TLS 1.0 Handshake [length 0010], Finished
[peap] TLS_accept: SSLv3 write finished A
[peap] TLS_accept: SSLv3 flush data
[peap] (other): SSL negotiation finished successfully
SSL Connection Established
[peap] eaptls_process returned 13
[peap] EAPTLS_HANDLED
++[eap] returns handled
Sending Access-Challenge of id 136 to 10.5.9.101 port 1812
EAP-Message = 0x01230039190014030100010116030100280f960fbeda49a00bbed93f1f2eadddeee331e1ca2d81d3ea7529089aaa62216a65a0cee3ded5e08f
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xc6470902c564104f0da0a4cab4725122
Finished request 140.
Going to the next request
Waking up in 0.3 seconds.
rad_recv: Access-Request packet from host 10.5.9.101 port 1812, id=137, length=167
NAS-IP-Address = 10.5.9.101
NAS-Port = 50016
Cisco-NAS-Port = "FastEthernet0/16"
NAS-Port-Type = Ethernet
User-Name = "test-printer"
Called-Station-Id = "00-0E-D7-74-D1-10"
Calling-Station-Id = "00-1F-29-23-BA-41"
Service-Type = Framed-User
Framed-MTU = 1500
State = 0xc6470902c564104f0da0a4cab4725122
EAP-Message = 0x022300061900
Message-Authenticator = 0xe4d996dd2229df66df329a0b4fca6ffd
+- entering group authorize {...}
[preprocess] expand: %{Client-IP-Address} -> 10.5.9.101
[preprocess] expand: %{Client-IP-Address} -> 10.5.9.101
[preprocess] expand: %{Client-IP-Address} -> 10.5.9.101
++[preprocess] returns ok
[suffix] No '@' in User-Name = "test-printer", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[ntdomain] No '\' in User-Name = "test-printer", looking up realm NULL
[ntdomain] No such realm "NULL"
++[ntdomain] returns noop
++? if ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/)
expand: %{User-Name} -> test-printer
? Evaluating ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/) -> TRUE
++? if ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/) -> TRUE
++- entering if ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/) {...}
+++? if (!"%{2}" || ("%{2}" == "realm.org") || ("%{2}" == "realm.com") )
expand: %{2} ->
? Evaluating !("%{2}" ) -> FALSE
? Skipping ("%{2}" == "realm.org")
? Skipping ("%{2}" == "realm.com")
+++? if (!"%{2}" || ("%{2}" == "realm.org") || ("%{2}" == "realm.com") ) -> TRUE
+++- entering if (!"%{2}" || ("%{2}" == "realm.org") || ("%{2}" == "realm.com") ) {...}
++++[request] returns noop
+++- if (!"%{2}" || ("%{2}" == "realm.org") || ("%{2}" == "realm.com") ) returns noop
+++ ... skipping else for request 141: Preceding "if" was taken
++- if ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/) returns noop
++ ... skipping else for request 141: Preceding "if" was taken
++? if ("%{Called-Station-Id}" =~ /.*:testssid$/ || "%{NAS-IP-Address}" =~ /10.5\.2\.[2|3|5|6|7]$/ )
expand: %{Called-Station-Id} -> 00-0E-D7-74-D1-10
? Evaluating ("%{Called-Station-Id}" =~ /.*:testssid$/) -> FALSE
expand: %{NAS-IP-Address} -> 10.5.9.101
Evaluating ("%{NAS-IP-Address}" =~ /10.5\.2\.[2|3|5|6|7]$/) -> FALSE
++? if ("%{Called-Station-Id}" =~ /.*:testssid$/ || "%{NAS-IP-Address}" =~ /10.5\.2\.[2|3|5|6|7]$/ ) -> FALSE
expand: %{Realm} -> local
++- entering switch %{Realm} {...}
+++- entering case local {...}
++++- case local returns notfound
+++- switch %{Realm} returns notfound
++- switch %{Realm} returns notfound
add-dollar-sign: Could not find value pair for attribute Stripped-User-Name
++[add-dollar-sign] returns noop
strip-realm-name: Could not find value pair for attribute Stripped-User-Name
++[strip-realm-name] returns noop
remove-lboro: Could not find value pair for attribute Stripped-User-Name
++[remove-lboro] returns noop
[auth_log] expand: /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/radius/radacct/10.5.9.101/auth-detail-20090113
[auth_log] /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/radius/radacct/10.5.9.101/auth-detail-20090113
[auth_log] expand: %t -> Tue Jan 13 12:11:22 2009
++[auth_log] returns ok
++[mschap] returns noop
[eap] EAP packet type response id 35 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 137 to 10.5.9.101 port 1812
EAP-Message = 0x0124002b190017030100200da2bc0e5a8aed6ce30468ee20c847ed63177985462e5d8d4a4706933d092e8b
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xc6470902c263104f0da0a4cab4725122
Finished request 141.
Going to the next request
Waking up in 0.3 seconds.
rad_recv: Access-Request packet from host 10.5.9.101 port 1812, id=138, length=241
NAS-IP-Address = 10.5.9.101
NAS-Port = 50016
Cisco-NAS-Port = "FastEthernet0/16"
NAS-Port-Type = Ethernet
User-Name = "test-printer"
Called-Station-Id = "00-0E-D7-74-D1-10"
Calling-Station-Id = "00-1F-29-23-BA-41"
Service-Type = Framed-User
Framed-MTU = 1500
State = 0xc6470902c263104f0da0a4cab4725122
EAP-Message = 0x0224005019001703010018e5fb1ee723ada3002395a0bde643333441f15026f4174ee317030100280ed31e191ab1b1f40db20230a94bf620670959f87755e14a71caa623bec80034691ab2e049315572
Message-Authenticator = 0xeb22067fa5350466c10a1f4b7395e4c1
+- entering group authorize {...}
[preprocess] expand: %{Client-IP-Address} -> 10.5.9.101
[preprocess] expand: %{Client-IP-Address} -> 10.5.9.101
[preprocess] expand: %{Client-IP-Address} -> 10.5.9.101
++[preprocess] returns ok
[suffix] No '@' in User-Name = "test-printer", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[ntdomain] No '\' in User-Name = "test-printer", looking up realm NULL
[ntdomain] No such realm "NULL"
++[ntdomain] returns noop
++? if ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/)
expand: %{User-Name} -> test-printer
? Evaluating ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/) -> TRUE
++? if ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/) -> TRUE
++- entering if ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/) {...}
+++? if (!"%{2}" || ("%{2}" == "realm.org") || ("%{2}" == "realm.com") )
expand: %{2} ->
? Evaluating !("%{2}" ) -> FALSE
? Skipping ("%{2}" == "realm.org")
? Skipping ("%{2}" == "realm.com")
+++? if (!"%{2}" || ("%{2}" == "realm.org") || ("%{2}" == "realm.com") ) -> TRUE
+++- entering if (!"%{2}" || ("%{2}" == "realm.org") || ("%{2}" == "realm.com") ) {...}
++++[request] returns noop
+++- if (!"%{2}" || ("%{2}" == "realm.org") || ("%{2}" == "realm.com") ) returns noop
+++ ... skipping else for request 142: Preceding "if" was taken
++- if ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/) returns noop
++ ... skipping else for request 142: Preceding "if" was taken
++? if ("%{Called-Station-Id}" =~ /.*:testssid$/ || "%{NAS-IP-Address}" =~ /10.5\.2\.[2|3|5|6|7]$/ )
expand: %{Called-Station-Id} -> 00-0E-D7-74-D1-10
? Evaluating ("%{Called-Station-Id}" =~ /.*:testssid$/) -> FALSE
expand: %{NAS-IP-Address} -> 10.5.9.101
Evaluating ("%{NAS-IP-Address}" =~ /10.5\.2\.[2|3|5|6|7]$/) -> FALSE
++? if ("%{Called-Station-Id}" =~ /.*:testssid$/ || "%{NAS-IP-Address}" =~ /10.5\.2\.[2|3|5|6|7]$/ ) -> FALSE
expand: %{Realm} -> local
++- entering switch %{Realm} {...}
+++- entering case local {...}
++++- case local returns notfound
+++- switch %{Realm} returns notfound
++- switch %{Realm} returns notfound
add-dollar-sign: Could not find value pair for attribute Stripped-User-Name
++[add-dollar-sign] returns noop
strip-realm-name: Could not find value pair for attribute Stripped-User-Name
++[strip-realm-name] returns noop
remove-lboro: Could not find value pair for attribute Stripped-User-Name
++[remove-lboro] returns noop
[auth_log] expand: /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/radius/radacct/10.5.9.101/auth-detail-20090113
[auth_log] /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/radius/radacct/10.5.9.101/auth-detail-20090113
[auth_log] expand: %t -> Tue Jan 13 12:11:22 2009
++[auth_log] returns ok
++[mschap] returns noop
[eap] EAP packet type response id 36 length 80
[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] Got something weird.
[peap] Tunneled data is invalid.
[eap] Handler failed in EAP/peap
[eap] Failed in EAP select
++[eap] returns invalid
Failed to authenticate the user.
Login incorrect: [test-printer] (from client Cisco-AP port 50016 cli 00-1F-29-23-BA-41)
Using Post-Auth-Type Reject
+- entering group REJECT {...}
[attr_filter.access_reject] expand: %{User-Name} -> test-printer
attr_filter: Matched entry DEFAULT at line 11
++[attr_filter.access_reject] returns updated
Delaying reject of request 142 for 1 seconds
Going to the next request
Waking up in 0.2 seconds.
Cleaning up request 130 ID 126 with timestamp +1535
Cleaning up request 131 ID 127 with timestamp +1536
Cleaning up request 132 ID 128 with timestamp +1536
Cleaning up request 133 ID 129 with timestamp +1536
Waking up in 0.1 seconds.
Cleaning up request 134 ID 130 with timestamp +1536
Cleaning up request 135 ID 131 with timestamp +1536
Waking up in 0.4 seconds.
Sending delayed reject for request 142
Sending Access-Reject of id 138 to 10.5.9.101 port 1812
EAP-Message = 0x04240004
Message-Authenticator = 0x00000000000000000000000000000000
Waking up in 0.6 seconds.
Cleaning up request 136 ID 132 with timestamp +1536
Cleaning up request 137 ID 133 with timestamp +1537
Cleaning up request 138 ID 134 with timestamp +1537
Cleaning up request 139 ID 135 with timestamp +1537
Waking up in 0.1 seconds.
Cleaning up request 140 ID 136 with timestamp +1537
Cleaning up request 141 ID 137 with timestamp +1537
Waking up in 1.0 seconds.
Cleaning up request 142 ID 138 with timestamp +1537
Ready to process requests.
More information about the Freeradius-Users
mailing list